Launchpad itself

bugs/+index timing out because of big queries

Bug #252674 reported by Ursula Junque
26
Affects Status Importance Assigned to Milestone
Launchpad itself
Fix Released
Medium
Björn Tillenius
Launchpad itself 2.1.9

Bug Description

As seen on OOPS-939A1430, OOPS-939F1337, OOPS-939F1340, OOPS-939F1347, OOPS-939F1354, OOPS-939F1385, OOPS-939F1406, OOPS-939F1411, OOPS-939F1412, OOPS-939F1414, bugs/+index is timing out with less than 5 seconds total time.

Needs to be verified since there were 38 occurrences of this timeout in only one day.

The query is ran to fill in the recently fixed bugs section of the bugs index page.

Exception type: TimeoutError
Exception value: 'SELECT BugTask.assignee, BugTask.bug, BugTask.bugwatch, BugTask.date_assigned, BugTask.date_closed, BugTask.date_confirmed, BugTask.date_fix_committed, BugTask.date_fix_released, BugTask.date_incomplete, BugTask.date_inprogress, BugTask.date_left_new, BugTask.date_triaged, BugTask.datecreated, BugTask.distribution, BugTask.distroseries, BugTask.id, BugTask.importance, BugTask.milestone, BugTask.owner, BugTask.product, BugTask.productseries, BugTask.sourcepackagename, BugTask.status, BugTask.statusexplanation, BugTask.targetnamecache, "_prejoin1".active, "_prejoin1".autoupdate, "_prejoin1".bug_reporting_guidelines, "_prejoin1".bug_supervisor, "_prejoin1".bugtracker, "_prejoin1".datecreated, "_prejoin1".description, "_prejoin1".development_focus, "_prejoin1".displayname, "_prejoin1".downloadurl, "_prejoin1".driver, "_prejoin1".enable_bug_expiration, "_prejoin1".freshmeatproject, "_prejoin1".homepage_content, "_prejoin1".homepageurl, "_prejoin1".icon, "_prejoin1".id, "_prejoin1".lastdoap, "_prejoin1".license_approved, "_prejoin1".license_info, "_prejoin1".reviewed, "_prejoin1".logo, "_prejoin1".mugshot, "_prejoin1".name, "_prejoin1".official_answers, "_prejoin1".official_blueprints, "_prejoin1".official_codehosting, "_prejoin1".official_malone, "_prejoin1".official_rosetta, "_prejoin1".owner, "_prejoin1".private_bugs, "_prejoin1".programminglang, "_prejoin1".project, "_prejoin1".reviewer_whiteboard, "_prejoin1".screenshotsurl, "_prejoin1".security_contact, "_prejoin1".sourceforgeproject, "_prejoin1".summary, "_prejoin1".title, "_prejoin1".translationgroup, "_prejoin1".translationpermission, "_prejoin1".wikiurl, "_prejoin2".id, "_prejoin2".name, Bug.date_last_message, Bug.date_last_updated, Bug.date_made_private, Bug.datecreated, Bug.description, Bug.duplicateof, Bug.id, Bug.message_count, Bug.name, Bug.number_of_duplicates, Bug.owner, Bug.private, Bug.security_related, Bug.title, Bug.who_made_private FROM Bug, BugTask LEFT JOIN Product AS "_prejoin1" ON BugTask.product = "_prejoin1".id LEFT JOIN SourcePackageName AS "_prejoin2" ON BugTask.sourcepackagename = "_prejoin2".id WHERE Bug.id = BugTask.bug AND (BugTask.status = 30) AND Bug.private = FALSE AND (1=1) ORDER BY BugTask.date_closed DESC, BugTask.id LIMIT 20 OFFSET 0', ()

Revision history for this message
Ursula Junque (ursinha) wrote :

Last occurrences: OOPS-943A2193, OOPS-943A2195, OOPS-943A2225, OOPS-943A2253, OOPS-943F2030, OOPS-943G852, OOPS-943G861, OOPS-943G879

Said in 31th july weekly meeting: BjortT is going to have to check with the losas to get more information.

Revision history for this message
Ursula Junque (ursinha) wrote :

BjornT asked for some new oopses: OOPS-956A2112, OOPS-956A2683, OOPS-956A2689. The time increased a little, but it's still below the timeout's limits.

Revision history for this message
Ursula Junque (ursinha) wrote :

OOPS-957A1896, OOPS-957A1902, OOPS-957A1907, OOPS-957A2474, OOPS-957A2504, OOPS-957A2506, OOPS-957A2509, OOPS-957C1702, OOPS-957C1708, OOPS-957C1711

Revision history for this message
Ursula Junque (ursinha) wrote :

Raising the priority since it's been happening quite often.

Changed in malone:
importance: Undecided → Medium
Revision history for this message
Graham Binns (gmb) wrote :

There's an XXX comment by BjornT above the line of code that's causing the problem (browser/bug.py:334):

We might end up returning less than :limit: bugs, but in
most cases we won't, and '4*limit' is here to prevent
this page from timing out in production. Later I'll fix
this properly by selecting bugs instead of bugtasks.
If fixed_bugtasks isn't sliced, it will take a long time
to iterate over it, even over just 10, because
Transaction.iterSelect() listifies the result.

I wonder if the workaround that this XXX marks is no longer working around the problem.

Revision history for this message
Jeroen T. Vermeulen (jtv) wrote :

Graham, that could have something to do with it. It's surprising though, because postgres 8.3 is smarter in dealing with the LIMIT and avoiding unnecessary sorting etc. Perhaps this is a performance regression associated with that.

On this query I see no fewer than 3 sequential scans: on BugTask, Bug, and SourcePackageName. We may have an incredilicious database setup but it's still a lot to ask for. The SourcePackageName one is cheap though, so jettisoning the prejoins probably doesn't help.

Revision history for this message
Jeroen T. Vermeulen (jtv) wrote :

This query looks for the 5 most recently closed bugs. Best solution I've found so far for speeding it up is to limit it to just BugTasks with a date_closed in (say) the last month. (That also changes current behaviour: the current query also includes fix-released BugTasks that don't have a date_closed, and those nulls come out of the sort first, which is probably not what's intended).

A subquery retrieving only distinct bug ids among the recently fix-released bugtasks is quite fast. After that it's no problem to join to Bug etc. and sort by date_closed. Adding in the private bugs that the current user is subscribed to (not shown above) is still slow, but if you retrieve the private-subscribed bugs and the public ones in separate queries you get your results much faster than querying them together with an "OR" clause added in.

Björn Tillenius (bjornt)
Changed in malone:
assignee: nobody → bjornt
milestone: none → 2.1.9
status: New → Triaged
Björn Tillenius (bjornt)
Changed in malone:
status: Triaged → In Progress
Revision history for this message
Björn Tillenius (bjornt) wrote :

Fixed in RF 6957.

Changed in malone:
status: In Progress → Fix Committed
Björn Tillenius (bjornt)
Changed in malone:
status: Fix Committed → Fix Released
Curtis Hovey (sinzui)
visibility: private → public
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.