Bug #609012 “+distrotask timeout” : Bugs : Launchpad itself

Micah Gersten (micahg) on 2010-07-23

description:	updated
description:	updated

Robert Collins (lifeless) on 2010-07-23

Changed in malone:
status:	New → Triaged
importance:	Undecided → High
description:	updated

Robert Collins (lifeless) on 2010-07-25

tags:

removed: oops

Revision history for this message

Robert Collins (lifeless) wrote on 2010-07-25:

#1

Download full text (14.7 KiB)

261 14003ms launchpad-main-master SELECT PublishedPackage.archive, PublishedPackage.binarypackagedescription, PublishedPackage.binarypackagename, PublishedPackage.binarypackagerelease, PublishedPackage.binarypackagesummary, PublishedPackage.binarypackageversion, PublishedPackage.build, PublishedPackage.component, PublishedPackage.datebuilt, PublishedPackage.distribution, PublishedPackage.distroarchseries, PublishedPackage.distroseries, PublishedPackage.distroseriesname, PublishedPackage.id, PublishedPackage.packagepublishingstatus, PublishedPackage.processorfamily, PublishedPackage.processorfamilyname, PublishedPackage.section, PublishedPackage.sourcepackagename, PublishedPackage.sourcepackagerelease, PublishedPackage.sourcepackagereleaseversion FROM PublishedPackage WHERE PublishedPackage.sourcepackagename = 'firefox' AND PublishedPackage.binarypackagename = 'firefox' AND PublishedPackage.distribution = 1 AND PublishedPackage.archive IN (1, 534) ORDER BY PublishedPackage.id DESC LIMIT 1

this performs inconsistently, and slowly at best.

Time: 362.676 ms is the best I got out of it on staging.

this is a bad one:
Limit (cost=419.90..419.91 rows=1 width=582) (actual time=36657.518..36657.519 rows=1 loops=1)
   -> Sort (cost=419.90..419.91 rows=1 width=582) (actual time=36657.514..36657.514 rows=1 loops=1)
         Sort Key: securebinarypackagepublishinghistory.id
         Sort Method: top-N heapsort Memory: 25kB
         -> Nested Loop (cost=2.80..419.89 rows=1 width=582) (actual time=32965.453..36657.057 rows=79 loops=1)
               -> Nested Loop (cost=2.80..419.30 rows=2 width=562) (actual time=32932.258..36479.947 rows=1474 loops=1)
                     Join Filter: (distroarchseries.processorfamily = processorfamily.id)
                     -> Nested Loop (cost=2.80..416.94 rows=2 width=530) (actual time=32932.241..36456.794 rows=1474 loops=1)
                           Join Filter: (component.id = securebinarypackagepublishinghistory.component)
                           -> Nested Loop (cost=2.80..414.63 rows=2 width=502) (actual time=32932.227..36436.532 rows=1474 loops=1)
                                 Join Filter: (section.id = securebinarypackagepublishinghistory.section)
                                 -> Nested Loop (cost=2.80..410.15 rows=2 width=500) (actual time=32932.166..36315.251 rows=1474 loops=1)
                                       -> Nested Loop (cost=2.80..397.47 rows=2 width=496) (actual time=32932.149..36300.168 rows=1474 loops=1)
                                             Join Filter: (distroseries.id = distroarchseries.distroseries)
                                             -> Seq Scan on distroseries (cost=0.00..2.38 rows=1 width=40) (actual time=0.022..0.092 rows=13 loops=1)
                                                   Filter: (distribution = 1)
                                             -> Hash Join (cost=2.80..394.46 rows=51 width=460) (actual time=475.780..2791.158 rows=1474 loops=13)
                                                   Hash Cond: (securebinarypackagepublishinghistory.distroarchseries = distroarchseries.id)
                                               ...

261	14003ms	launchpad-main-master	SELECT PublishedPackage.archive, PublishedPackage.binarypackagedescription, PublishedPackage.binarypackagename, PublishedPackage.binarypackagerelease, PublishedPackage.binarypackagesummary, PublishedPackage.binarypackageversion, PublishedPackage.build, PublishedPackage.component, PublishedPackage.datebuilt, PublishedPackage.distribution, PublishedPackage.distroarchseries, PublishedPackage.distroseries, PublishedPackage.distroseriesname, PublishedPackage.id, PublishedPackage.packagepublishingstatus, PublishedPackage.processorfamily, PublishedPackage.processorfamilyname, PublishedPackage.section, PublishedPackage.sourcepackagename, PublishedPackage.sourcepackagerelease, PublishedPackage.sourcepackagereleaseversion FROM PublishedPackage WHERE PublishedPackage.sourcepackagename = 'firefox' AND PublishedPackage.binarypackagename = 'firefox' AND PublishedPackage.distribution = 1 AND PublishedPackage.archive IN (1, 534) ORDER BY PublishedPackage.id DESC LIMIT 1

this performs inconsistently, and slowly at best.

Time: 362.676 ms is the best I got out of it on staging.

this is a bad one:
 Limit  (cost=419.90..419.91 rows=1 width=582) (actual time=36657.518..36657.519 rows=1 loops=1)
   ->  Sort  (cost=419.90..419.91 rows=1 width=582) (actual time=36657.514..36657.514 rows=1 loops=1)
         Sort Key: securebinarypackagepublishinghistory.id
         Sort Method:  top-N heapsort  Memory: 25kB
         ->  Nested Loop  (cost=2.80..419.89 rows=1 width=582) (actual time=32965.453..36657.057 rows=79 loops=1)
               ->  Nested Loop  (cost=2.80..419.30 rows=2 width=562) (actual time=32932.258..36479.947 rows=1474 loops=1)
                     Join Filter: (distroarchseries.processorfamily = processorfamily.id)
                     ->  Nested Loop  (cost=2.80..416.94 rows=2 width=530) (actual time=32932.241..36456.794 rows=1474 loops=1)
                           Join Filter: (component.id = securebinarypackagepublishinghistory.component)
                           ->  Nested Loop  (cost=2.80..414.63 rows=2 width=502) (actual time=32932.227..36436.532 rows=1474 loops=1)
                                 Join Filter: (section.id = securebinarypackagepublishinghistory.section)
                                 ->  Nested Loop  (cost=2.80..410.15 rows=2 width=500) (actual time=32932.166..36315.251 rows=1474 loops=1)
                                       ->  Nested Loop  (cost=2.80..397.47 rows=2 width=496) (actual time=32932.149..36300.168 rows=1474 loops=1)
                                             Join Filter: (distroseries.id = distroarchseries.distroseries)
                                             ->  Seq Scan on distroseries  (cost=0.00..2.38 rows=1 width=40) (actual time=0.022..0.092 rows=13 loops=1)
                                                   Filter: (distribution = 1)
                                             ->  Hash Join  (cost=2.80..394.46 rows=51 width=460) (actual time=475.780..2791.158 rows=1474 loops=13)
                                                   Hash Cond: (securebinarypackagepublishinghistory.distroarchseries = distroarchseries.id)
                                                   ->  Nested Loop  (cost=0.00..390.96 rows=51 width=452) (actual time=475.755..2788.496 rows=1474 loops=13)
                                                         ->  Nested Loop  (cost=0.00..367.84 rows=51 width=452) (actual time=475.737..2777.061 rows=1474 loops=13)
                                                               ->  Nested Loop  (cost=0.00..179.89 rows=127 width=428) (actual time=0.066..568.942 rows=25648 loops=13)
                                                                     ->  Nested Loop  (cost=0.00..19.51 rows=49 width=42) (actual time=0.054..43.922 rows=2933 loops=13)
                                                                           ->  Nested Loop  (cost=0.00..7.93 rows=18 width=34) (actual time=0.040..3.877 rows=879 loops=13)
                                                                                 ->  Index Scan using sourcepackagename_name_key on sourcepackagename  (cost=0.00..6.27 rows=1 width=17) (actual time=0.015..0.018 rows=1 loops=13)
                                                                                       Index Cond: (name = 'firefox'::text)
                                                                                 ->  Index Scan using sourcepackagerelease_sourcepackagename_idx on sourcepackagerelease  (cost=0.00..1.09 rows=45 width=25) (actual time=0.021..2.538 rows=879 loops=13)
                                                                                       Index Cond: (sourcepackagerelease.sourcepackagename = sourcepackagename.id)
                                                                           ->  Index Scan using binarypackagebuild__source_package_release_idx on binarypackagebuild  (cost=0.00..0.57 rows=6 width=12) (actual time=0.027..0.040 rows=3 loops=11427)
                                                                                 Index Cond: (binarypackagebuild.source_package_release = sourcepackagerelease.id)
                                                                     ->  Index Scan using binarypackagerelease_build_idx on binarypackagerelease  (cost=0.00..2.61 rows=53 width=390) (actual time=0.051..0.164 rows=9 loops=38129)
                                                                           Index Cond: (binarypackagerelease.build = binarypackagebuild.id)
                                                               ->  Index Scan using securebinarypackagepublishinghistory_binarypackagerelease_idx on binarypackagepublishinghistory securebinarypackagepublishinghistory  (cost=0.00..1.45 rows=2 width=28) (actual time=0.083..0.085 rows=0 loops=333424)
                                                                     Index Cond: (securebinarypackagepublishinghistory.binarypackagerelease = binarypackagerelease.id)
                                                                     Filter: ((securebinarypackagepublishinghistory.dateremoved IS NULL) AND (securebinarypackagepublishinghistory.archive = ANY ('{1,534}'::integer[])))
                                                         ->  Index Scan using tmp_packagebuild__id__bfj__key on packagebuild  (cost=0.00..0.44 rows=1 width=8) (actual time=0.004..0.005 rows=1 loops=19162)
                                                               Index Cond: (packagebuild.id = binarypackagebuild.package_build)
                                                   ->  Hash  (cost=1.80..1.80 rows=80 width=12) (actual time=0.186..0.186 rows=80 loops=1)
                                                         ->  Seq Scan on distroarchseries  (cost=0.00..1.80 rows=80 width=12) (actual time=0.013..0.090 rows=80 loops=1)
                                       ->  Index Scan using tmp_buildfarmjob__id__status__key on buildfarmjob  (cost=0.00..6.33 rows=1 width=12) (actual time=0.006..0.007 rows=1 loops=1474)
                                             Index Cond: (buildfarmjob.id = packagebuild.build_farm_job)
                                 ->  Seq Scan on section  (cost=0.00..1.55 rows=55 width=10) (actual time=0.003..0.037 rows=55 loops=1474)
                           ->  Seq Scan on component  (cost=0.00..1.07 rows=7 width=36) (actual time=0.001..0.006 rows=7 loops=1474)
                     ->  Seq Scan on processorfamily  (cost=0.00..1.08 rows=8 width=36) (actual time=0.001..0.007 rows=8 loops=1474)
               ->  Index Scan using binarypackagename_pkey on binarypackagename  (cost=0.00..0.28 rows=1 width=28) (actual time=0.118..0.118 rows=0 loops=1474)
                     Index Cond: (binarypackagename.id = binarypackagerelease.binarypackagename)
                     Filter: (binarypackagename.name = 'firefox'::text)
 Total runtime: 36657.946 ms
(47 rows)

Time: 36798.762 ms

And a faster one:

Limit  (cost=710.50..710.50 rows=1 width=582) (actual time=593.457..593.458 rows=1 loops=1)
   ->  Sort  (cost=710.50..710.50 rows=1 width=582) (actual time=593.455..593.455 rows=1 loops=1)
         Sort Key: securebinarypackagepublishinghistory.id
         Sort Method:  top-N heapsort  Memory: 25kB
         ->  Nested Loop  (cost=8.47..710.49 rows=1 width=582) (actual time=136.979..593.238 rows=79 loops=1)
               ->  Nested Loop  (cost=8.47..710.02 rows=1 width=578) (actual time=136.961..592.544 rows=79 loops=1)
                     Join Filter: (sourcepackagename.id = sourcepackagerelease.sourcepackagename)
                     ->  Nested Loop  (cost=8.47..703.68 rows=1 width=565) (actual time=136.930..590.965 rows=192 loops=1)
                           ->  Nested Loop  (cost=8.47..697.40 rows=1 width=548) (actual time=136.913..589.471 rows=192 loops=1)
                                 Join Filter: (distroarchseries.distroseries = distroseries.id)
                                 ->  Seq Scan on distroseries  (cost=0.00..2.38 rows=1 width=40) (actual time=0.017..0.070 rows=13 loops=1)
                                       Filter: (distribution = 1)
                                 ->  Hash Join  (cost=8.47..694.85 rows=14 width=512) (actual time=1.455..45.202 rows=192 loops=13)
                                       Hash Cond: (securebinarypackagepublishinghistory.component = component.id)
                                       ->  Hash Join  (cost=7.32..693.50 rows=14 width=484) (actual time=1.451..44.905 rows=192 loops=13)
                                             Hash Cond: (securebinarypackagepublishinghistory.section = section.id)
                                             ->  Hash Join  (cost=5.08..691.07 rows=14 width=482) (actual time=1.442..44.601 rows=192 loops=13)
                                                   Hash Cond: (securebinarypackagepublishinghistory.distroarchseries = distroarchseries.id)
                                                   ->  Nested Loop  (cost=0.00..685.80 rows=14 width=442) (actual time=1.419..44.237 rows=192 loops=13)
                                                         ->  Nested Loop  (cost=0.00..679.45 rows=14 width=442) (actual time=1.406..42.865 rows=192 loops=13)
                                                               ->  Nested Loop  (cost=0.00..663.65 rows=14 width=434) (actual time=1.394..41.453 rows=192 loops=13)
                                                                     ->  Nested Loop  (cost=0.00..611.86 rows=35 width=410) (actual time=0.037..10.407 rows=3023 loops=13)
                                                                           ->  Index Scan using binarypackagename_name_key on binarypackagename  (cost=0.00..6.29 rows=1 width=28) (actual time=0.013..0.015 rows=1 loops=13)
                                                                                 Index Cond: (name = 'firefox'::text)
                                                                           ->  Index Scan using binarypackagerelease_binarypackagename_key on binarypackagerelease  (cost=0.00..602.74 rows=226 width=390) (actual time=0.020..5.806 rows=3023 loops=13)
                                                                                 Index Cond: (binarypackagerelease.binarypackagename = binarypackagename.id)
                                                                     ->  Index Scan using securebinarypackagepublishinghistory_binarypackagerelease_idx on binarypackagepublishinghistory securebinarypackagepublishinghistory  (cost=0.00..1.45 rows=2 width=28) (actual time=0.009..0.009 rows=0 loops=39299)
                                                                           Index Cond: (securebinarypackagepublishinghistory.binarypackagerelease = binarypackagerelease.id)
                                                                           Filter: ((securebinarypackagepublishinghistory.dateremoved IS NULL) AND (securebinarypackagepublishinghistory.archive = ANY ('{1,534}'::integer[])))
                                                               ->  Index Scan using binarypackagebuild_pkey on binarypackagebuild  (cost=0.00..1.12 rows=1 width=12) (actual time=0.004..0.005 rows=1 loops=2496)
                                                                     Index Cond: (binarypackagebuild.id = binarypackagerelease.build)
                                                         ->  Index Scan using tmp_packagebuild__id__bfj__key on packagebuild  (cost=0.00..0.44 rows=1 width=8) (actual time=0.004..0.004 rows=1 loops=2496)
                                                               Index Cond: (packagebuild.id = binarypackagebuild.package_build)
                                                   ->  Hash  (cost=4.08..4.08 rows=80 width=44) (actual time=0.259..0.259 rows=80 loops=1)
                                                         ->  Hash Join  (cost=1.18..4.08 rows=80 width=44) (actual time=0.037..0.190 rows=80 loops=1)
                                                               Hash Cond: (distroarchseries.processorfamily = processorfamily.id)
                                                               ->  Seq Scan on distroarchseries  (cost=0.00..1.80 rows=80 width=12) (actual time=0.007..0.051 rows=80 loops=1)
                                                               ->  Hash  (cost=1.08..1.08 rows=8 width=36) (actual time=0.018..0.018 rows=8 loops=1)
                                                                     ->  Seq Scan on processorfamily  (cost=0.00..1.08 rows=8 width=36) (actual time=0.004..0.008 rows=8 loops=1)
                                             ->  Hash  (cost=1.55..1.55 rows=55 width=10) (actual time=0.086..0.086 rows=55 loops=1)
                                                   ->  Seq Scan on section  (cost=0.00..1.55 rows=55 width=10) (actual time=0.005..0.042 rows=55 loops=1)
                                       ->  Hash  (cost=1.07..1.07 rows=7 width=36) (actual time=0.020..0.020 rows=7 loops=1)
                                             ->  Seq Scan on component  (cost=0.00..1.07 rows=7 width=36) (actual time=0.004..0.008 rows=7 loops=1)
                           ->  Index Scan using sourcepackagename_name_key on sourcepackagename  (cost=0.00..6.27 rows=1 width=17) (actual time=0.004..0.005 rows=1 loops=192)
                                 Index Cond: (sourcepackagename.name = 'firefox'::text)
                     ->  Index Scan using sourcepackagerelease_pkey on sourcepackagerelease  (cost=0.00..6.32 rows=1 width=25) (actual time=0.004..0.005 rows=1 loops=192)
                           Index Cond: (sourcepackagerelease.id = binarypackagebuild.source_package_release)
               ->  Index Scan using tmp_buildfarmjob__id__status__key on buildfarmjob  (cost=0.00..0.45 rows=1 width=12) (actual time=0.005..0.006 rows=1 loops=79)
                     Index Cond: (buildfarmjob.id = packagebuild.build_farm_job)
 Total runtime: 593.779 ms
(50 rows)

Time: 742.619 ms

Revision history for this message

Stuart Bishop (stub) wrote on 2010-07-29: Re: [Bug 609012] Re: +distrotask timeout

#2

PublishedPackage is a view that joins 13 tables. If we need to query
this in the appserver, we will likely need to materialize it.
Hopefully we don't need to. We need to see what information this page
actually needs to display - if the view is doing unnecessary work we
should avoid using it.

--
Stuart Bishop <email address hidden>
http://www.stuartbishop.net/

Revision history for this message

Micah Gersten (micahg) wrote on 2010-08-03:

#3

Here's one where I was just trying to link to Debian upstream:
https://bugs.edge.launchpad.net/ubuntu/+bug/612824/+distrotask
OOPS-1676ED3105

Revision history for this message

Micah Gersten (micahg) wrote on 2010-08-03:

#4

Now it happened in production :(
OOPS-1676K1464
https://bugs.launchpad.net/ubuntu/+bug/612824/+distrotask

Robert Collins (lifeless) on 2010-08-10

Changed in malone:
status:	Triaged → Fix Committed
assignee:	nobody → William Grant (wgrant)
milestone:	none → 10.08

William Grant (wgrant) on 2010-08-12

Changed in malone:
status:	Fix Committed → Fix Released

Launchpad itself

+distrotask timeout

Bug Description

Duplicates of this bug

Other bug subscribers

Remote bug watches