BugTask:+index timeout due to high cpu time rendering many bug tasks in bug 230350

Bug #724025 reported by Robert Collins on 2011-02-24
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Launchpad itself
Critical
Unassigned

Bug Description

OOPS-1927B436
OOPS-1880F2434

Branch: launchpad-rev-12432
Revno: 12432
SQL time: 2582 ms
Non-sql time: 12602 ms
Total time: 15184 ms
Statement Count: 315

Related branches

description: updated
William Grant (wgrant) wrote :

OOPS-1962DU69 is a bit more modern. 5s gap between 59 and 60, and 59 should only have returned a single row.

William Grant (wgrant) wrote :

OOPS-1943DR70 shows the same thing.

Gary Poster (gary) on 2011-08-03
Changed in launchpad:
assignee: nobody → Gary Poster (gary)
Gary Poster (gary) wrote :

I did a kcachegrind profile of this. I was disappointed with its ability to accurately identify/show caller/callee relationships beyond a high level. I may look at the raw files more later. The profiles do seem to indicate that the cost is happening somewhere within pagetemplate rendering--which really could indicate really any number of causes, since I'm not able to drill down deep enough to know. KCacheGrind allows a maximum of 499 calls shown, which is not nearly enough, thanks at least in part to the page template code itself.

Next steps are to examine the DB records and see if I can find something unusual about this bug, perhaps on the basis of some of the queries before the 5s gap; and failing that to grope through the profile log itself.

Gary Poster (gary) wrote :

Looks like this bug has 159 bug tasks, associated with 158 unique source packages. That's the obvious problem, looking through the SQL, and there are no other candidates that I see. That rings a bell: I wonder if this is a dupe.

summary: - BugTask:+index timeout due to high cpu time rendering bug 230350
+ BugTask:+index timeout due to high cpu time rendering many bug tasks in
+ bug 230350
Gary Poster (gary) wrote :

bug 636158 seems to be the closest parallel. Fix Released. This looks like we need another increment of work on the problem.

Data point: the last time I saw very high CPU it was due to storm
object comparisons:

if A == B, when A and B are storm objects (e.g. SQLBase derived) is
very expensive; any algorithm which involves a lot of such comparisons
will lead to high python time.

e.g. if A in something
-> fine if something is a dict or set
-> trouble if something is a list or tuple

-Rob

Gary Poster (gary) on 2011-08-11
Changed in launchpad:
status: Triaged → In Progress
Launchpad QA Bot (lpqabot) wrote :
tags: added: qa-needstesting
Changed in launchpad:
status: In Progress → Fix Committed
Henning Eggers (henninge) wrote :

QA note: The bugs from the OOPSes still time out on qastaging but then that is qastaging. We will have to wait until it hits production to know if the bug is actually fixed.

I verified that other bugs still display properly and that bugtasks are not expandable when there are 10 or more of them (many_bugtasks).

tags: added: qa-ok
removed: qa-needstesting
Gary Poster (gary) wrote :

As Henning notes, this seems to be an insufficient improvement. It's fine to go out to production, but this needs more analysis and work.

Changed in launchpad:
status: Fix Committed → In Progress

I got it loaded on the first attempt today on production in 7.6s. Loading it with ++oops++ got me:

    At least 802 queries/external actions issued in 6.34 seconds OOPS-2050H26

Launchpad QA Bot (lpqabot) wrote :
tags: added: qa-needstesting
removed: qa-ok
Gary Poster (gary) on 2011-08-24
tags: added: qa-ok
removed: qa-needstesting
Launchpad QA Bot (lpqabot) wrote :
tags: added: qa-needstesting
removed: qa-ok
Changed in launchpad:
status: In Progress → Fix Committed
William Grant (wgrant) wrote :

Bad, but untagged revert in r13794.

tags: added: qa-ok
removed: qa-needstesting
William Grant (wgrant) on 2011-08-26
Changed in launchpad:
status: Fix Committed → In Progress
Launchpad QA Bot (lpqabot) wrote :
tags: added: qa-needstesting
removed: qa-ok
Gary Poster (gary) on 2011-08-30
tags: added: qa-bad
removed: qa-needstesting
Launchpad QA Bot (lpqabot) wrote :
tags: added: qa-needstesting
removed: qa-bad
Changed in launchpad:
status: In Progress → Fix Committed
Gary Poster (gary) on 2011-09-03
tags: added: qa-ok
removed: qa-needstesting
Changed in launchpad:
assignee: Gary Poster (gary) → nobody
status: Fix Committed → Triaged
Gary Poster (gary) wrote :

I'm moving on. Note that this bug (230350) has many bug tasks, and many branches. As of this writing, it has about 50% more bugtasks than any other bug in Launchpad, and also the most branches.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers