/maas-project/+activereviews times out

Bug #1847090 reported by Colin Watson
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Launchpad itself
Fix Released
Critical
Colin Watson

Bug Description

https://code.launchpad.net/maas-project/+activereviews times out with OOPS-e35685f694a2d3e2a03d3a9c3598c04b. EXPLAIN (ANALYZE, BUFFERS) of the slow query says:

 Sort (cost=22784.36..22784.36 rows=2 width=864) (actual time=8487.022..8487.023 rows=7 loops=1)
   Sort Key: branchmergeproposal.date_created DESC, branchmergeproposal.id
   Sort Method: quicksort Memory: 31kB
   Buffers: shared hit=1636424
   -> Unique (cost=22784.18..22784.33 rows=2 width=864) (actual time=8486.988..8487.009 rows=7 loops=1)
         Buffers: shared hit=1636424
         -> Sort (cost=22784.18..22784.18 rows=2 width=864) (actual time=8486.987..8486.987 rows=7 loops=1)
               Sort Key: branchmergeproposal.commit_message, branchmergeproposal.date_created, branchmergeproposal.date_merged, branchmergeproposal.date_review_requested, branchmergeproposal.date_reviewed, branchmergeproposal.description, branchmergeproposal.id, branchmergeproposal.merge_reporter, branchmergeproposal.merged_revision_id, branchmergeproposal.merged_revno, branchmergeproposal.dependent_branch, branchmergeproposal.dependent_git_commit_sha1, branchmergeproposal.dependent_git_path, branchmergeproposal.dependent_git_repository, branchmergeproposal.queue_status, branchmergeproposal.registrant, branchmergeproposal.reviewed_revision_id, branchmergeproposal.reviewer, branchmergeproposal.root_message_id, branchmergeproposal.source_branch, branchmergeproposal.source_git_commit_sha1, branchmergeproposal.source_git_path, branchmergeproposal.source_git_repository, branchmergeproposal.superseded_by, branchmergeproposal.target_branch, branchmergeproposal.target_git_commit_sha1, branchmergeproposal.target_git_path, branchmergeproposal.target_git_repository, branchmergeproposal.whiteboard
               Sort Method: quicksort Memory: 31kB
               Buffers: shared hit=1636424
               -> Append (cost=636.84..22784.17 rows=2 width=864) (actual time=8486.947..8486.950 rows=7 loops=1)
                     Buffers: shared hit=1636424
                     -> Sort (cost=636.84..636.85 rows=1 width=944) (actual time=59.592..59.592 rows=0 loops=1)
                           Sort Key: branchmergeproposal.date_created DESC, branchmergeproposal.id
                           Sort Method: quicksort Memory: 25kB
                           Buffers: shared hit=44221
                           CTE candidate_branches
                             -> Nested Loop (cost=26.63..356.32 rows=69 width=4) (actual time=0.036..17.506 rows=8557 loops=1)
                                   Buffers: shared hit=10099
                                   InitPlan 4 (returns $5)
                                     -> Aggregate (cost=4.25..4.26 rows=1 width=32) (actual time=0.072..0.072 rows=1 loops=1)
                                           Buffers: shared hit=35
                                           -> Index Scan using teamparticipation_person_idx on teamparticipation teamparticipation_2 (cost=0.43..4.24 rows=2 width=4) (actual time=0.013..0.052 rows=42 loops=1)
                                                 Index Cond: (person = 862235)
                                                 Buffers: shared hit=35
                                   InitPlan 5 (returns $7)
                                     -> Aggregate (cost=21.65..21.66 rows=1 width=32) (actual time=1.749..1.749 rows=1 loops=1)
                                           Buffers: shared hit=1461
                                           -> Nested Loop (cost=0.85..21.64 rows=1 width=4) (actual time=0.024..1.432 rows=1931 loops=1)
                                                 Buffers: shared hit=1461
                                                 -> Index Scan using teamparticipation_person_idx on teamparticipation teamparticipation_3 (cost=0.43..4.24 rows=2 width=4) (actual time=0.008..0.031 rows=42 loops=1)
                                                       Index Cond: (person = 862235)
                                                       Buffers: shared hit=35
                                                 -> Index Only Scan using accesspolicygrant__grantee__policy__key on accesspolicygrant accesspolicygrant_1 (cost=0.42..8.66 rows=4 width=8) (actual time=0.004..0.027 rows=46 loops=42)
                                                       Index Cond: (grantee = teamparticipation_3.team)
                                                       Heap Fetches: 1931
                                                       Buffers: shared hit=1426
                                   -> Index Scan using product_project_idx on product product_1 (cost=0.29..9.36 rows=4 width=4) (actual time=0.016..0.018 rows=3 loops=1)
                                         Index Cond: (project = 698)
                                         Buffers: shared hit=5
                                   -> Index Scan using branch__product__owner__name__key on branch (cost=0.42..79.82 rows=44 width=8) (actual time=0.009..5.432 rows=2852 loops=3)
                                         Index Cond: (product = product_1.id)
                                         Filter: ((information_type = ANY ('{1,2}'::integer[])) OR COALESCE((access_grants && $5), false) OR COALESCE((ARRAY[access_policy] && $7), false))
                                         Buffers: shared hit=10094
                           -> Hash Semi Join (cost=4.22..280.52 rows=1 width=944) (actual time=59.586..59.586 rows=0 loops=1)
                                 Hash Cond: (branchmergeproposal.target_branch = candidate_branches_1.id)
                                 Buffers: shared hit=44221
                                 -> Nested Loop (cost=1.98..278.27 rows=3 width=944) (actual time=37.029..37.029 rows=0 loops=1)
                                       Buffers: shared hit=34122
                                       -> HashAggregate (cost=1.55..2.24 rows=69 width=4) (actual time=3.878..6.003 rows=8557 loops=1)
                                             Group Key: candidate_branches.id
                                             -> CTE Scan on candidate_branches (cost=0.00..1.38 rows=69 width=4) (actual time=0.001..0.807 rows=8557 loops=1)
                                       -> Index Scan using branchmergeproposal__source_branch__idx on branchmergeproposal (cost=0.42..3.99 rows=1 width=944) (actual time=0.003..0.003 rows=0 loops=8557)
                                             Index Cond: (source_branch = candidate_branches.id)
                                             Filter: (queue_status = ANY ('{3,2}'::integer[]))
                                             Rows Removed by Filter: 1
                                             Buffers: shared hit=34122
                                 -> Hash (cost=1.38..1.38 rows=69 width=4) (actual time=22.543..22.543 rows=8557 loops=1)
                                       Buckets: 16384 (originally 1024) Batches: 1 (originally 1) Memory Usage: 429kB
                                       Buffers: shared hit=10099
                                       -> CTE Scan on candidate_branches candidate_branches_1 (cost=0.00..1.38 rows=69 width=4) (actual time=0.038..20.592 rows=8557 loops=1)
                                             Buffers: shared hit=10099
                     -> Sort (cost=22147.29..22147.30 rows=1 width=944) (actual time=8427.353..8427.354 rows=7 loops=1)
                           Sort Key: branchmergeproposal_1.date_created DESC, branchmergeproposal_1.id
                           Sort Method: quicksort Memory: 31kB
                           Buffers: shared hit=1592203
                           CTE candidate_repositories
                             -> Nested Loop (cost=28.33..78.49 rows=1 width=4) (actual time=0.040..2.588 rows=89 loops=1)
                                   Buffers: shared hit=1595
                                   InitPlan 1 (returns $0)
                                     -> Aggregate (cost=4.25..4.26 rows=1 width=32) (actual time=0.063..0.063 rows=1 loops=1)
                                           Buffers: shared hit=35
                                           -> Index Scan using teamparticipation_person_idx on teamparticipation (cost=0.43..4.24 rows=2 width=4) (actual time=0.013..0.049 rows=42 loops=1)
                                                 Index Cond: (person = 862235)
                                                 Buffers: shared hit=35
                                   InitPlan 2 (returns $2)
                                     -> Aggregate (cost=21.65..21.66 rows=1 width=32) (actual time=1.745..1.745 rows=1 loops=1)
                                           Buffers: shared hit=1461
                                           -> Nested Loop (cost=0.85..21.64 rows=1 width=4) (actual time=0.016..1.444 rows=1931 loops=1)
                                                 Buffers: shared hit=1461
                                                 -> Index Scan using teamparticipation_person_idx on teamparticipation teamparticipation_1 (cost=0.43..4.24 rows=2 width=4) (actual time=0.006..0.029 rows=42 loops=1)
                                                       Index Cond: (person = 862235)
                                                       Buffers: shared hit=35
                                                 -> Index Only Scan using accesspolicygrant__grantee__policy__key on accesspolicygrant (cost=0.42..8.66 rows=4 width=8) (actual time=0.003..0.027 rows=46 loops=42)
                                                       Index Cond: (grantee = teamparticipation_1.team)
                                                       Heap Fetches: 1931
                                                       Buffers: shared hit=1426
                                   -> Index Scan using product_project_idx on product (cost=0.29..9.36 rows=4 width=4) (actual time=0.008..0.011 rows=3 loops=1)
                                         Index Cond: (project = 698)
                                         Buffers: shared hit=5
                                   -> Bitmap Heap Scan on gitrepository (cost=2.12..10.77 rows=4 width=8) (actual time=0.022..0.850 rows=30 loops=3)
                                         Recheck Cond: (project = product.id)
                                         Filter: ((information_type = ANY ('{1,2}'::integer[])) OR COALESCE((access_grants && $0), false) OR COALESCE((ARRAY[access_policy] && $2), false))
                                         Heap Blocks: exact=87
                                         Buffers: shared hit=1590
                                         -> Bitmap Index Scan on gitrepository__project__id__idx (cost=0.00..2.12 rows=5 width=0) (actual time=0.008..0.008 rows=30 loops=3)
                                               Index Cond: (project = product.id)
                                               Buffers: shared hit=7
                           -> Nested Loop Semi Join (cost=0.02..22068.79 rows=1 width=944) (actual time=1528.623..8427.311 rows=7 loops=1)
                                 Join Filter: (branchmergeproposal_1.target_git_repository = candidate_repositories_1.id)
                                 Rows Removed by Join Filter: 406
                                 Buffers: shared hit=1592203
                                 -> Nested Loop (cost=0.02..22068.76 rows=1 width=944) (actual time=1528.606..8427.197 rows=7 loops=1)
                                       Join Filter: (branchmergeproposal_1.source_git_repository = candidate_repositories.id)
                                       Rows Removed by Join Filter: 1071286
                                       Buffers: shared hit=1592203
                                       -> HashAggregate (cost=0.02..0.03 rows=1 width=4) (actual time=2.670..2.956 rows=89 loops=1)
                                             Group Key: candidate_repositories.id
                                             Buffers: shared hit=1595
                                             -> CTE Scan on candidate_repositories (cost=0.00..0.02 rows=1 width=4) (actual time=0.043..2.624 rows=89 loops=1)
                                                   Buffers: shared hit=1595
                                       -> Seq Scan on branchmergeproposal branchmergeproposal_1 (cost=0.00..21917.71 rows=12081 width=944) (actual time=0.033..92.441 rows=12037 loops=89)
                                             Filter: (queue_status = ANY ('{3,2}'::integer[]))
                                             Rows Removed by Filter: 311620
                                             Buffers: shared hit=1590608
                                 -> CTE Scan on candidate_repositories candidate_repositories_1 (cost=0.00..0.02 rows=1 width=4) (actual time=0.001..0.007 rows=59 loops=7)
 Planning time: 12.965 ms
 Execution time: 8487.565 ms
(118 rows)

This appears to be due to missing indexes on BranchMergeProposal(*_git_repository).

Related branches

Revision history for this message
Colin Watson (cjwatson) wrote :

DB patch applied live, and the page no longer times out.

Changed in launchpad:
status: In Progress → Fix Released
martin (mukamuka)
affects: launchpad → ubuntu
Changed in ubuntu:
assignee: Colin Watson (cjwatson) → martin (mukamuka)
Colin Watson (cjwatson)
affects: ubuntu → launchpad
Changed in launchpad:
assignee: martin (mukamuka) → Colin Watson (cjwatson)
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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