This query is contstructed using the Django ORM on top of PostgreSQL 11 (latest). PostgreSQL here is running in a docker container. In production we are using Cloud SQL, and query times are faster but overall quite slow.
Update: Query and EXPLAIN ANALYZE
also available here: https://explain.depesz.com/s/yQE7
I have indexed on all ID columns, so I was surprised when EXPLAIN
showed a prohibitively long full table scan on orders_query
. The long-running piece is in the very top of the EXPLAIN
log, but here's the relevant portion (the very top lines):
GroupAggregate (cost=999695.25..19231670646.03 rows=1897315 width=105)
Group Key: users_profile.id, users_user.last_login
-> Sort (cost=999695.25..1007470.17 rows=3109968 width=73)
Sort Key: users_profile.id, users_user.last_login
-> Hash Right Join (cost=738.71..387928.02 rows=3109968 width=73)
Hash Cond: (orders_query.user_id = users_user.id)
-> Seq Scan on orders_query (cost=0.00..345054.24 rows=2943324 width=8)
-> Hash (cost=702.78..702.78 rows=2874 width=73)
-> Hash Right Join (cost=301.35..702.78 rows=2874 width=73)
Question: Is there another index I can make to avoid this Seq Scan
that slows down the SQL query?
SELECT "users_profile"."id",
"users_profile"."created",
"users_profile"."modified",
"users_profile"."guid",
"users_profile"."user_id",
"users_profile"."charter_role_id",
"users_profile"."owner_id",
"users_profile"."volume_limit",
"users_profile"."vol_limit_ovrd",
"users_profile"."charter_vol_limit_contrib_ovrd",
"users_profile"."sponsored_ovrd",
"users_profile"."view_peers_ovrd",
"users_profile"."inherit_permits",
Count(DISTINCT "orders_order"."id") AS "orders",
(SELECT Count(DISTINCT U0."guid") AS "io"
FROM "orders_order" U0
INNER JOIN "users_user" U1
ON ( U0."user_id" = U1."id" )
INNER JOIN "users_profile" U2
ON ( U1."id" = U2."user_id" )
WHERE U2."owner_id" = "users_profile"."id"
GROUP BY U2."owner_id") AS "indirect_orders",
Count(DISTINCT "orders_query"."id") AS "searches",
(SELECT Count(DISTINCT U0."guid") AS "isch"
FROM "orders_query" U0
INNER JOIN "users_user" U1
ON ( U0."user_id" = U1."id" )
INNER JOIN "users_profile" U2
ON ( U1."id" = U2."user_id" )
WHERE U2."owner_id" = "users_profile"."id"
GROUP BY U2."owner_id") AS "indirect_searches",
(SELECT Count(DISTINCT U0."guid") AS "sg"
FROM "users_profile" U0
WHERE U0."owner_id" = "users_profile"."id"
GROUP BY U0."owner_id") AS "signups",
"users_user"."last_login" AS "last_activity"
FROM "users_profile"
INNER JOIN "users_user"
ON ( "users_profile"."user_id" = "users_user"."id" )
LEFT OUTER JOIN "orders_order"
ON ( "users_user"."id" = "orders_order"."user_id" )
LEFT OUTER JOIN "orders_query"
ON ( "users_user"."id" = "orders_query"."user_id" )
GROUP BY "users_profile"."id",
"users_user"."last_login"
EXPLAIN ANALYZE
EXPLAIN ANALYZE
GroupAggregate (cost=999695.25..19231670646.03 rows=1897315 width=105) (actual time=682829.362..1112031.341 rows=1057 loops=1)
" Group Key: users_profile.id, users_user.last_login"
-> Sort (cost=999695.25..1007470.17 rows=3109968 width=73) (actual time=682711.948..768155.952 rows=222437142 loops=1)
" Sort Key: users_profile.id, users_user.last_login"
Sort Method: external merge Disk: 18873640kB
-> Hash Right Join (cost=738.71..387928.02 rows=3109968 width=73) (actual time=12.263..115509.811 rows=222437142 loops=1)
Hash Cond: (orders_query.user_id = users_user.id)
-> Seq Scan on orders_query (cost=0.00..345054.24 rows=2943324 width=8) (actual time=0.024..6992.146 rows=2945348 loops=1)
-> Hash (cost=702.78..702.78 rows=2874 width=73) (actual time=12.203..12.203 rows=3456 loops=1)
Buckets: 4096 Batches: 1 Memory Usage: 409kB
-> Hash Right Join (cost=301.35..702.78 rows=2874 width=73) (actual time=3.807..10.194 rows=3456 loops=1)
Hash Cond: (orders_order.user_id = users_user.id)
-> Seq Scan on orders_order (cost=0.00..344.96 rows=7396 width=8) (actual time=0.009..1.771 rows=7396 loops=1)
-> Hash (cost=288.13..288.13 rows=1057 width=69) (actual time=3.762..3.762 rows=1057 loops=1)
Buckets: 2048 Batches: 1 Memory Usage: 128kB
-> Hash Join (cost=36.78..288.13 rows=1057 width=69) (actual time=1.137..3.169 rows=1057 loops=1)
Hash Cond: (users_user.id = users_profile.user_id)
-> Seq Scan on users_user (cost=0.00..244.20 rows=2720 width=12) (actual time=0.014..0.610 rows=2720 loops=1)
-> Hash (cost=23.57..23.57 rows=1057 width=57) (actual time=1.022..1.174 rows=1057 loops=1)
Buckets: 2048 Batches: 1 Memory Usage: 113kB
-> Seq Scan on users_profile (cost=0.00..23.57 rows=1057 width=57) (actual time=0.008..0.504 rows=1057 loops=1)
SubPlan 1
-> GroupAggregate (cost=4.96..87.25 rows=14 width=12) (actual time=0.016..0.016 rows=0 loops=1057)
Group Key: u2.owner_id
-> Nested Loop (cost=4.96..86.89 rows=44 width=20) (actual time=0.008..0.013 rows=2 loops=1057)
-> Nested Loop (cost=4.68..71.05 rows=16 width=12) (actual time=0.005..0.008 rows=1 loops=1057)
-> Bitmap Heap Scan on users_profile u2 (cost=4.40..18.29 rows=16 width=8) (actual time=0.003..0.004 rows=1 loops=1057)
Recheck Cond: (owner_id = users_profile.id)
Heap Blocks: exact=300
-> Bitmap Index Scan on users_profile_owner_id_a9029da4 (cost=0.00..4.40 rows=16 width=0) (actual time=0.002..0.002 rows=1 loops=1057)
Index Cond: (owner_id = users_profile.id)
-> Index Only Scan using users_user_pkey on users_user u1 (cost=0.28..3.30 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=1037)
Index Cond: (id = u2.user_id)
Heap Fetches: 0
-> Index Scan using orders_order_user_id_e9b59eb1 on orders_order u0 (cost=0.28..0.89 rows=10 width=20) (actual time=0.003..0.004 rows=2 loops=1037)
Index Cond: (user_id = u1.id)
SubPlan 2
-> GroupAggregate (cost=0.99..10029.94 rows=14 width=12) (actual time=5.109..5.109 rows=0 loops=1057)
Group Key: u2_1.owner_id
-> Nested Loop (cost=0.99..9943.23 rows=17314 width=20) (actual time=0.197..4.366 rows=858 loops=1057)
-> Nested Loop (cost=0.56..110.20 rows=16 width=12) (actual time=0.182..0.196 rows=1 loops=1057)
-> Index Scan using users_profile_user_id_key on users_profile u2_1 (cost=0.28..57.44 rows=16 width=8) (actual time=0.182..0.192 rows=1 loops=1057)
Filter: (owner_id = users_profile.id)
Rows Removed by Filter: 1056
-> Index Only Scan using users_user_pkey on users_user u1_1 (cost=0.28..3.30 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=1037)
Index Cond: (id = u2_1.user_id)
Heap Fetches: 0
-> Index Scan using orders_query_user_id_a0b49874 on orders_query u0_1 (cost=0.43..564.34 rows=5022 width=20) (actual time=0.038..4.010 rows=874 loops=1037)
Index Cond: (user_id = u1_1.id)
SubPlan 3
-> GroupAggregate (cost=4.40..18.51 rows=14 width=12) (actual time=0.005..0.005 rows=0 loops=1057)
Group Key: u0_2.owner_id
-> Bitmap Heap Scan on users_profile u0_2 (cost=4.40..18.29 rows=16 width=20) (actual time=0.002..0.002 rows=1 loops=1057)
Recheck Cond: (owner_id = users_profile.id)
Heap Blocks: exact=300
-> Bitmap Index Scan on users_profile_owner_id_a9029da4 (cost=0.00..4.40 rows=16 width=0) (actual time=0.001..0.001 rows=1 loops=1057)
Index Cond: (owner_id = users_profile.id)
Planning Time: 4.279 ms
Execution Time: 1112994.119 ms
EXPLAIN
GroupAggregate (cost=999695.25..19231670646.03 rows=1897315 width=105)
Group Key: users_profile.id, users_user.last_login
-> Sort (cost=999695.25..1007470.17 rows=3109968 width=73)
Sort Key: users_profile.id, users_user.last_login
-> Hash Right Join (cost=738.71..387928.02 rows=3109968 width=73)
Hash Cond: (orders_query.user_id = users_user.id)
-> Seq Scan on orders_query (cost=0.00..345054.24 rows=2943324 width=8)
-> Hash (cost=702.78..702.78 rows=2874 width=73)
-> Hash Right Join (cost=301.35..702.78 rows=2874 width=73)
Hash Cond: (orders_order.user_id = users_user.id)
-> Seq Scan on orders_order (cost=0.00..344.96 rows=7396 width=8)
-> Hash (cost=288.13..288.13 rows=1057 width=69)
-> Hash Join (cost=36.78..288.13 rows=1057 width=69)
Hash Cond: (users_user.id = users_profile.user_id)
-> Seq Scan on users_user (cost=0.00..244.20 rows=2720 width=12)
-> Hash (cost=23.57..23.57 rows=1057 width=57)
-> Seq Scan on users_profile (cost=0.00..23.57 rows=1057 width=57)
SubPlan 1
-> GroupAggregate (cost=4.96..87.25 rows=14 width=12)
Group Key: u2.owner_id
-> Nested Loop (cost=4.96..86.89 rows=44 width=20)
-> Nested Loop (cost=4.68..71.05 rows=16 width=12)
-> Bitmap Heap Scan on users_profile u2 (cost=4.40..18.29 rows=16 width=8)
Recheck Cond: (owner_id = users_profile.id)
-> Bitmap Index Scan on users_profile_owner_id_a9029da4 (cost=0.00..4.40 rows=16 width=0)
Index Cond: (owner_id = users_profile.id)
-> Index Only Scan using users_user_pkey on users_user u1 (cost=0.28..3.30 rows=1 width=4)
Index Cond: (id = u2.user_id)
-> Index Scan using orders_order_user_id_e9b59eb1 on orders_order u0 (cost=0.28..0.89 rows=10 width=20)
Index Cond: (user_id = u1.id)
SubPlan 2
-> GroupAggregate (cost=0.99..10029.94 rows=14 width=12)
Group Key: u2_1.owner_id
-> Nested Loop (cost=0.99..9943.23 rows=17314 width=20)
-> Nested Loop (cost=0.56..110.20 rows=16 width=12)
-> Index Scan using users_profile_user_id_key on users_profile u2_1 (cost=0.28..57.44 rows=16 width=8)
Filter: (owner_id = users_profile.id)
-> Index Only Scan using users_user_pkey on users_user u1_1 (cost=0.28..3.30 rows=1 width=4)
Index Cond: (id = u2_1.user_id)
-> Index Scan using orders_query_user_id_a0b49874 on orders_query u0_1 (cost=0.43..564.34 rows=5022 width=20)
Index Cond: (user_id = u1_1.id)
SubPlan 3
-> GroupAggregate (cost=4.40..18.51 rows=14 width=12)
Group Key: u0_2.owner_id
-> Bitmap Heap Scan on users_profile u0_2 (cost=4.40..18.29 rows=16 width=20)
Recheck Cond: (owner_id = users_profile.id)
-> Bitmap Index Scan on users_profile_owner_id_a9029da4 (cost=0.00..4.40 rows=16 width=0)
Index Cond: (owner_id = users_profile.id)
It looks to me like you're joining each of a user's "orders_order" with each of their "orders_query", yielding far too many rows in the result (200 million) which then need to be sorted for the group by, which takes a long time.
Try writing subqueries for "orders" and "searches" the same way you did for "indirect_orders" and "indirect_searches", so that you can remove those two left outer joins.