Archive:+index timeouts

Bug #691478 reported by Robert Collins
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Launchpad itself
Fix Released
Critical
Julian Edwards

Bug Description

 260 (SELECT SourcePackagePublishingHistory.ancestor, SourcePackagePublishingHistory.archive, SourcePa ... mJob.status IN (%s) ORDER BY SourcePackagePublishingHistory.id, DistroArchSeries.architecturetag):
   GET: 235 POST: 2 Other: 23 Robots: 15 Local: 74
     51 https://launchpad.net/%7Exorg-edgers/+archive/ppa/+index (Archive:+index)
       OOPS-1857C1105, OOPS-1857C1261, OOPS-1857C1477, OOPS-1857C1480, OOPS-1857C2230
     39 https://launchpad.net/%7Ekubuntu-ppa/+archive/backports/+index (Archive:+index)
       OOPS-1857C2339, OOPS-1857C2368, OOPS-1857C2369, OOPS-1857C2962, OOPS-1857C648
     33 https://launchpad.net/%7Ezend-framework/+archive/ppa/+index (Archive:+index)
       OOPS-1857A403, OOPS-1857A404, OOPS-1857A405, OOPS-1857A406, OOPS-1857C507

Taking OOPS-1857A403

Branch: launchpad-rev-12274
Revno: 12274
SQL time: 13968 ms
Non-sql time: 402 ms
Total time: 14370 ms
Statement Count: 50

The query count is tolerable; single largest query is
1 1309.0 1 SQL-launchpad-main-slave
SELECT *
FROM (
        (SELECT BinaryPackageBuild.distro_arch_series, BinaryPackageBuild.id, BinaryPackageBuild.package_build, BinaryPackageBuild.source_package_release
         FROM BinaryPackageBuild, BinaryPackagePublishingHistory, BinaryPackageRelease, BuildFarmJob, DistroArchSeries, PackageBuild, SourcePackagePublishingHistory
         WHERE BinaryPackageBuild.package_build = PackageBuild.id
           AND BinaryPackageBuild.distro_arch_series = DistroArchSeries.id
           AND SourcePackagePublishingHistory.distroseries = DistroArchSeries.distroseries
           AND SourcePackagePublishingHistory.sourcepackagerelease = BinaryPackageBuild.source_package_release
           AND SourcePackagePublishingHistory.id IN (%s, %s, %s, %s, %s, %s)
           AND SourcePackagePublishingHistory.archive != PackageBuild.archive
           AND BinaryPackagePublishingHistory.archive = SourcePackagePublishingHistory.archive
           AND BinaryPackagePublishingHistory.binarypackagerelease = BinaryPackageRelease.id
           AND BinaryPackageRelease.build = BinaryPackageBuild.id
           AND BinaryPackageBuild.package_build = PackageBuild.id
           AND PackageBuild.build_farm_job = BuildFarmJob.id
           AND BuildFarmJob.status IN (%s)
         ORDER BY BinaryPackageBuild.id)
      UNION
        (SELECT BinaryPackageBuild.distro_arch_series, BinaryPackageBuild.id, BinaryPackageBuild.package_build, BinaryPackageBuild.source_package_release
         FROM BinaryPackageBuild, BuildFarmJob, DistroArchSeries, PackageBuild, SourcePackagePublishingHistory
         WHERE BinaryPackageBuild.package_build = PackageBuild.id
           AND BinaryPackageBuild.distro_arch_series = DistroArchSeries.id
           AND SourcePackagePublishingHistory.distroseries = DistroArchSeries.distroseries
           AND SourcePackagePublishingHistory.sourcepackagerelease = BinaryPackageBuild.source_package_release
           AND SourcePackagePublishingHistory.id IN (%s, %s, %s, %s, %s, %s)
           AND SourcePackagePublishingHistory.archive = PackageBuild.archive
           AND BinaryPackageBuild.package_build = PackageBuild.id
           AND PackageBuild.build_farm_job = BuildFarmJob.id
           AND BuildFarmJob.status IN (%s)
         ORDER BY BinaryPackageBuild.id)) AS "_294bf"
ORDER BY id

Tags: qa-ok timeout dba
description: updated
description: updated
description: updated
tags: added: dba
description: updated
Changed in launchpad:
importance: High → Critical
Changed in launchpad:
status: Triaged → In Progress
Revision history for this message
Launchpad QA Bot (lpqabot) wrote :
Changed in launchpad:
assignee: nobody → Julian Edwards (julian-edwards)
milestone: none → 11.02
tags: added: qa-needstesting
Changed in launchpad:
status: In Progress → Fix Committed
Revision history for this message
Julian Edwards (julian-edwards) wrote :

The fix takes a good chunk of time off the page load but it's still not great, this will need re-opening when we lower timeouts again.

tags: added: qa-ok
removed: qa-needstesting
Revision history for this message
Robert Collins (lifeless) wrote : Re: [Bug 691478] Re: Archive:+index timeouts

On Mon, Jan 24, 2011 at 3:02 AM, Julian Edwards
<email address hidden> wrote:
> The fix takes a good chunk of time off the page load

Sweet!

> but it's still not
> great, this will need re-opening when we lower timeouts again.

Softly softly catchee rabbit.

I have some new gotchas to look up in slow query plans - I'll document
this as a narrative for the list but see bug 706200 for the
as-I-figured-it-out story.

-Rob

William Grant (wgrant)
Changed in launchpad:
status: Fix Committed → Fix Released
Revision history for this message
Julian Edwards (julian-edwards) wrote :

Setting this back to Triaged since the last fix didn't really help much.

Changed in launchpad:
status: Fix Released → Triaged
description: updated
Changed in launchpad:
assignee: Julian Edwards (julian-edwards) → nobody
milestone: 11.02 → none
description: updated
Revision history for this message
Julian Edwards (julian-edwards) wrote :

I'm still looking at this!

Changed in launchpad:
assignee: nobody → Julian Edwards (julian-edwards)
Revision history for this message
Julian Edwards (julian-edwards) wrote :

There's a long query that's repeated 5 times, I'll sort it later.

Revision history for this message
Robert Collins (lifeless) wrote :

Oh cool; I wasn't sure given that the other metadata (e.g. milestone)
had been left unaltered; I was resetting it to ready-to-roll was all.

Revision history for this message
Julian Edwards (julian-edwards) wrote :

My latest finding is that ArchiveSourcePublications:.__iter__ ends up indirectly calling PublishingSet.getBuildsForSourceIds() multiple times via the methods:

 * self.getBuildsBySource(),
 * self.getUnpublishedBuildsBySource()
 * publishing_set.getBuildStatusSummariesForSourceIdsAndArchive()

The latest_updates property in ArchiveView also indirectly calls it via getStatusSummaryForBuilds()

The whole thing is such an incoherent mess, it's hard to know where to start.

Revision history for this message
Robert Collins (lifeless) wrote :

My basic approach in such cases is to try and define an API that figures out whats needed, drive that in a set based approach until it gets down to actual queries etc. but it is tricky; pick a thread and pull on it.

Revision history for this message
Robert Collins (lifeless) wrote :
Download full text (4.1 KiB)

Separately, this query is very slow: 2.2seconds

SELECT SourcePackagePublishingHistory.ancestor, SourcePackagePublishingHistory.archive, SourcePackagePublishingHistory.component, SourcePackagePublishingHistory.datecreated, SourcePackagePublishingHistory.datemadepending, SourcePackagePublishingHistory.datepublished, SourcePackagePublishingHistory.dateremoved, SourcePackagePublishingHistory.datesuperseded, SourcePackagePublishingHistory.distroseries, SourcePackagePublishingHistory.id, SourcePackagePublishingHistory.pocket, SourcePackagePublishingHistory.removal_comment, SourcePackagePublishingHistory.removed_by, SourcePackagePublishingHistory.scheduleddeletiondate, SourcePackagePublishingHistory.section, SourcePackagePublishingHistory.sourcepackagerelease, SourcePackagePublishingHistory.status, SourcePackagePublishingHistory.supersededby, "_prejoin1".user_defined_fields, "_prejoin1".architecturehintlist, "_prejoin1".build_conflicts, "_prejoin1".build_conflicts_indep, "_prejoin1".builddepends, "_prejoin1".builddependsindep, "_prejoin1".changelog, "_prejoin1".changelog_entry, "_prejoin1".component, "_prejoin1".copyright, "_prejoin1".creator, "_prejoin1".dateuploaded, "_prejoin1".dsc, "_prejoin1".dsc_binaries, "_prejoin1".dsc_format, "_prejoin1".dsc_maintainer_rfc822, "_prejoin1".dsc_standards_version, "_prejoin1".dscsigningkey, "_prejoin1".format, "_prejoin1".homepage, "_prejoin1".id, "_prejoin1".maintainer, "_prejoin1".section, "_prejoin1".sourcepackage_recipe_build, "_prejoin1".sourcepackagename, "_prejoin1".upload_archive, "_prejoin1".upload_distroseries, "_prejoin1".urgency, "_prejoin1".version, "_prejoin2".account, "_prejoin2".creation_comment, "_prejoin2".creation_rationale, "_prejoin2".datecreated, "_prejoin2".defaultmembershipperiod, "_prejoin2".defaultrenewalperiod, "_prejoin2".displayname, "_prejoin2".hide_email_addresses, "_prejoin2".homepage_content, "_prejoin2".icon, "_prejoin2".id, "_prejoin2".logo, "_prejoin2".mailing_list_auto_subscribe_policy, "_prejoin2".merged, "_prejoin2".mugshot, "_prejoin2".name, "_prejoin2".personal_standing, "_prejoin2".personal_standing_reason, "_prejoin2".registrant, "_prejoin2".renewal_policy, "_prejoin2".subscriptionpolicy, "_prejoin2".teamdescription, "_prejoin2".teamowner, "_prejoin2".verbose_bugnotifications, "_prejoin2".visibility, "_prejoin3".active, "_prejoin3".algorithm, "_prejoin3".can_encrypt, "_prejoin3".fingerprint, "_prejoin3".id, "_prejoin3".keyid, "_prejoin3".keysize, "_prejoin3".owner, "_prejoin4".binarycount, "_prejoin4".changeslist, "_prejoin4".date_created, "_prejoin4".datereleased, "_prejoin4".defer_translation_imports, "_prejoin4".description, "_prejoin4".displayname, "_prejoin4".distribution, "_prejoin4".driver, "_prejoin4".hide_all_translations, "_prejoin4".id, "_prejoin4".language_pack_base, "_prejoin4".language_pack_delta, "_prejoin4".language_pack_full_export_requested, "_prejoin4".language_pack_proposed, "_prejoin4".messagecount, "_prejoin4".name, "_prejoin4".nominatedarchindep, "_prejoin4".owner, "_prejoin4".parent_series, "_prejoin4".sourcecount, "_prejoin4".releasestatus, "_prejoin4".summary, "_prejoin4".title, "_prejoin4".version, "_prejoin5".id, "_prejoin5".name FROM Sour...

Read more...

Revision history for this message
Robert Collins (lifeless) wrote :

(ah, its the debversion_sort_key bug). Dropping the debversion_sort_key call drops 1.2 seconds off of this call.

Revision history for this message
Robert Collins (lifeless) wrote :

Dropping the prejoins makes it 380ms:
SELECT SourcePackagePublishingHistory.ancestor, SourcePackagePublishingHistory.archive, SourcePackagePublishingHistory.component, SourcePackagePublishingHistory.datecreated, SourcePackagePublishingHistory.datemadepending, SourcePackagePublishingHistory.datepublished, SourcePackagePublishingHistory.dateremoved, SourcePackagePublishingHistory.datesuperseded, SourcePackagePublishingHistory.distroseries, SourcePackagePublishingHistory.id, SourcePackagePublishingHistory.pocket, SourcePackagePublishingHistory.removal_comment, SourcePackagePublishingHistory.removed_by, SourcePackagePublishingHistory.scheduleddeletiondate, SourcePackagePublishingHistory.section, SourcePackagePublishingHistory.sourcepackagerelease, SourcePackagePublishingHistory.status, SourcePackagePublishingHistory.supersededby FROM SourcePackageName, SourcePackageRelease, SourcePackagePublishingHistory WHERE SourcePackagePublishingHistory.archive = 20931 AND SourcePackagePublishingHistory.sourcepackagerelease = SourcePackageRelease.id AND SourcePackageRelease.sourcepackagename = SourcePackageName.id AND SourcePackagePublishingHistory.status IN (1, 2) AND SourcePackagePublishingHistory.distroseries = 104 AND (1=1) ORDER BY SourcePackageName.name, SourcePackageRelease.version DESC, SourcePackagePublishingHistory.id DESC LIMIT 51 OFFSET 0;

Revision history for this message
Robert Collins (lifeless) wrote :

So, I'd say: 1) get the debversion datatype in place, 2) drop the prejoins and instead use pre_iter_hook to eager load the needed person, etc rows.

Revision history for this message
Julian Edwards (julian-edwards) wrote :

I've optimised some of the latest updates stuff - it was issuing multiple queries where one would do, see bug 713234 for tracking + fix.

Revision history for this message
Julian Edwards (julian-edwards) wrote :

xorg-edgers PPA:
77 queries/external actions issued in 9.27 seconds

with the soon-to-be-release code on qastaging:
66 queries/external actions issued in 6.94 seconds

Slowly getting there!

Revision history for this message
Julian Edwards (julian-edwards) wrote :

Let's open a new bug when required, this one's done for now and the page is no longer in the top 10 timeouts, although only *just*.

Changed in launchpad:
status: Triaged → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

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