Sample Header Ad - 728x90

Postgresql Aggregate Query With Sort Very Slow

0 votes
2 answers
614 views
I have a simple aggregate query that is running very slowly (198s) on a table with ~4.6mil rows, can anyone suggest how to optimise? SELECT u.user_id,u.firstname,u.surname,u.image_url,p.pool_name, count(s.session_id) as totalSwims,sum(s.total_time_in_seconds) as totalTotalTime from sessions as s left join user_sessions as us on us.session_id = s.session_id left join users as u on u.user_id = us.user_id left join user_prefs as up on up.user_id = u.user_id left join pools as p on p.pool_id = u.local_pool where p.client_id = 1 and s.requires_checking is false and s.swim_rating > 10 and us.user_id is not null and s.date_swam > '2023-03-01 01:59:54.962+00' and s.date_swam Seq Scan on public.pools p (cost=0.00..235.00 rows=62 width=33) (actual time=0.018..0.794 rows=61 loops=3) Output: p.pool_name, p.client_id, p.pool_id Filter: (p.client_id = 1) Rows Removed by Filter: 5674 Buffers: shared hit=486 Worker 0: actual time=0.018..0.651 rows=61 loops=1 Buffers: shared hit=162 Worker 1: actual time=0.019..0.790 rows=61 loops=1 Buffers: shared hit=162 -> Index Scan using user_prefs_pkey on public.user_prefs up (cost=0.42..3.77 rows=1 width=4) (actual time=0.079..0.079 rows=0 loops=61372) Output: up.user_id Index Cond: (up.user_id = u.user_id) Filter: (up.enable_public_leaderboards IS TRUE) Rows Removed by Filter: 1 Buffers: shared hit=239339 read=6309 dirtied=59 I/O Timings: read=4577.017 Worker 0: actual time=0.071..0.071 rows=0 loops=20288 Buffers: shared hit=79332 read=1879 dirtied=18 I/O Timings: read=1354.770 Worker 1: actual time=0.081..0.081 rows=0 loops=20803 Buffers: shared hit=81068 read=2195 dirtied=18 I/O Timings: read=1605.396 -> Index Only Scan using user_sessions_pkey on public.user_sessions us (cost=0.43..140.52 rows=154 width=8) (actual time=0.619..1.525 rows=73 loops=11592) Output: us.user_id, us.session_id Index Cond: ((us.user_id = u.user_id) AND (us.user_id IS NOT NULL)) Heap Fetches: 488381 Buffers: shared hit=498091 read=18665 I/O Timings: read=16850.427 Worker 0: actual time=0.634..1.555 rows=74 loops=3830 Buffers: shared hit=167709 read=6288 I/O Timings: read=5689.264 Worker 1: actual time=0.624..1.549 rows=73 loops=3790 Buffers: shared hit=164737 read=6208 I/O Timings: read=5598.264 -> Index Scan using sessions_pkey on public.sessions s (cost=0.43..4.00 rows=1 width=10) (actual time=0.676..0.676 rows=0 loops=845589) Output: s.session_id, s.total_time_in_seconds Index Cond: (s.session_id = us.session_id) Filter: ((s.requires_checking IS FALSE) AND (s.swim_rating > 10) AND (s.date_swam > '2023-03-01 01:59:54.962+00'::timestamp with time zone) AND (s.date_swam 10. I then dropped the session_id primary key index to force the planner to use the new index, it gives the following plan (updated a second time!).... Limit (cost=107902.84..107902.89 rows=20 width=140) (actual time=13760.459..13802.105 rows=20 loops=1) Output: u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, (count(s.session_id)), (sum(s.total_time_in_seconds)), p.client_id, p.pool_id Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 -> Sort (cost=107902.84..107902.94 rows=43 width=140) (actual time=13760.458..13802.101 rows=20 loops=1) Output: u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, (count(s.session_id)), (sum(s.total_time_in_seconds)), p.client_id, p.pool_id Sort Key: (sum(s.total_time_in_seconds)) DESC Sort Method: top-N heapsort Memory: 33kB Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 -> Finalize GroupAggregate (cost=107896.10..107901.69 rows=43 width=140) (actual time=13748.876..13801.273 rows=1476 loops=1) Output: u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, count(s.session_id), sum(s.total_time_in_seconds), p.client_id, p.pool_id Group Key: u.user_id, p.pool_id Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 -> Gather Merge (cost=107896.10..107900.71 rows=36 width=140) (actual time=13748.858..13797.814 rows=3340 loops=1) Output: u.user_id, p.pool_id, u.firstname, u.surname, u.image_url, p.pool_name, (PARTIAL count(s.session_id)), (PARTIAL sum(s.total_time_in_seconds)), p.client_id Workers Planned: 2 Workers Launched: 2 Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 -> Partial GroupAggregate (cost=106896.08..106896.53 rows=18 width=140) (actual time=13743.988..13746.974 rows=1113 loops=3) Output: u.user_id, p.pool_id, u.firstname, u.surname, u.image_url, p.pool_name, PARTIAL count(s.session_id), PARTIAL sum(s.total_time_in_seconds), p.client_id Group Key: u.user_id, p.pool_id Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 Worker 0: actual time=13741.803..13744.770 rows=1123 loops=1 Buffers: shared hit=262454 read=9464 dirtied=14, temp read=7403 written=7316 I/O Timings: read=12590.170 Worker 1: actual time=13742.976..13745.801 rows=1035 loops=1 Buffers: shared hit=258266 read=9090 dirtied=26, temp read=7763 written=8300 I/O Timings: read=12656.606 -> Sort (cost=106896.08..106896.12 rows=18 width=110) (actual time=13743.971..13744.390 rows=3256 loops=3) Output: u.user_id, p.pool_id, u.firstname, u.surname, u.image_url, p.pool_name, s.session_id, s.total_time_in_seconds, p.client_id Sort Key: u.user_id, p.pool_id Sort Method: quicksort Memory: 811kB Buffers: shared hit=771807 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 Worker 0: actual time=13741.780..13742.171 rows=3221 loops=1 Sort Method: quicksort Memory: 701kB Buffers: shared hit=262454 read=9464 dirtied=14, temp read=7403 written=7316 I/O Timings: read=12590.170 Worker 1: actual time=13742.958..13743.323 rows=2736 loops=1 Sort Method: quicksort Memory: 608kB Buffers: shared hit=258266 read=9090 dirtied=26, temp read=7763 written=8300 I/O Timings: read=12656.606 -> Parallel Hash Join (cost=34085.80..106895.70 rows=18 width=110) (actual time=13647.907..13741.713 rows=3256 loops=3) Output: u.user_id, p.pool_id, u.firstname, u.surname, u.image_url, p.pool_name, s.session_id, s.total_time_in_seconds, p.client_id Hash Cond: (s.session_id = us.session_id) Buffers: shared hit=771793 read=27894 dirtied=52, temp read=23232 written=23668 I/O Timings: read=38115.334 Worker 0: actual time=13655.793..13739.514 rows=3221 loops=1 Buffers: shared hit=262447 read=9464 dirtied=14, temp read=7403 written=7316 I/O Timings: read=12590.170 Worker 1: actual time=13644.134..13741.201 rows=2736 loops=1 Buffers: shared hit=258259 read=9090 dirtied=26, temp read=7763 written=8300 I/O Timings: read=12656.606 -> Parallel Bitmap Heap Scan on public.sessions s (cost=447.58..73224.60 rows=8746 width=10) (actual time=7.704..24.683 rows=15126 loops=3) Output: s.session_id, s.total_time_in_seconds Recheck Cond: ((s.date_swam > '2023-03-01 01:59:54.962+00'::timestamp with time zone) AND (s.date_swam 10)) Heap Blocks: exact=7524 Buffers: shared hit=19743 Worker 0: actual time=6.706..17.200 rows=7148 loops=1 Buffers: shared hit=3877 Worker 1: actual time=8.199..27.980 rows=20303 loops=1 Buffers: shared hit=8214 -> Bitmap Index Scan on sessions_date_swam_idx (cost=0.00..442.33 rows=20990 width=0) (actual time=4.946..4.946 rows=47051 loops=1) Index Cond: ((s.date_swam > '2023-03-01 01:59:54.962+00'::timestamp with time zone) AND (s.date_swam Parallel Hash (cost=33585.40..33585.40 rows=4226 width=104) (actual time=13599.941..13599.945 rows=283349 loops=3) Output: us.session_id, u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, p.client_id, p.pool_id Buckets: 32768 (originally 16384) Batches: 32 (originally 1) Memory Usage: 4032kB Buffers: shared hit=752034 read=27894 dirtied=52, temp read=10015 written=23284 I/O Timings: read=38115.334 Worker 0: actual time=13599.432..13599.437 rows=288936 loops=1 Buffers: shared hit=258562 read=9464 dirtied=14, temp read=2720 written=7188 I/O Timings: read=12590.170 Worker 1: actual time=13597.604..13597.609 rows=285810 loops=1 Buffers: shared hit=250037 read=9090 dirtied=26, temp read=3648 written=8172 I/O Timings: read=12656.606 -> Nested Loop (cost=239.54..33585.40 rows=4226 width=104) (actual time=6.219..13166.722 rows=283349 loops=3) Output: us.session_id, u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, p.client_id, p.pool_id Buffers: shared hit=752034 read=27894 dirtied=52 I/O Timings: read=38115.334 Worker 0: actual time=3.284..13087.841 rows=288936 loops=1 Buffers: shared hit=258562 read=9464 dirtied=14 I/O Timings: read=12590.170 Worker 1: actual time=7.931..13106.351 rows=285810 loops=1 Buffers: shared hit=250037 read=9090 dirtied=26 I/O Timings: read=12656.606 -> Nested Loop (cost=239.11..15989.40 rows=124 width=104) (actual time=5.013..1891.004 rows=3880 loops=3) Output: u.user_id, u.firstname, u.surname, u.image_url, up.user_id, p.pool_name, p.client_id, p.pool_id Inner Unique: true Buffers: shared hit=254626 read=4579 dirtied=52 I/O Timings: read=5183.492 Worker 0: actual time=1.601..1793.850 rows=4041 loops=1 Buffers: shared hit=90103 read=1608 dirtied=14 I/O Timings: read=1612.670 Worker 1: actual time=6.604..2114.870 rows=3960 loops=1 Buffers: shared hit=83066 read=1497 dirtied=26 I/O Timings: read=1968.382 -> Hash Join (cost=238.69..13655.78 rows=624 width=100) (actual time=0.954..42.871 rows=20490 loops=3) Output: u.user_id, u.firstname, u.surname, u.image_url, p.pool_name, p.client_id, p.pool_id Inner Unique: true Hash Cond: (u.local_pool = p.pool_id) Buffers: shared hit=13161 Worker 0: actual time=0.980..45.020 rows=21799 loops=1 Buffers: shared hit=4452 Worker 1: actual time=0.778..40.547 rows=19986 loops=1 Buffers: shared hit=4573 -> Parallel Seq Scan on public.users u (cost=0.00..13263.23 rows=58571 width=71) (actual time=0.007..27.779 rows=46880 loops=3) Output: u.user_id, u.firstname, u.surname, u.image_url, u.local_pool Filter: (u.disabled IS FALSE) Rows Removed by Filter: 664 Buffers: shared hit=12669 Worker 0: actual time=0.006..29.047 rows=49923 loops=1 Buffers: shared hit=4288 Worker 1: actual time=0.005..25.210 rows=45846 loops=1 Buffers: shared hit=4409 -> Hash (cost=237.90..237.90 rows=63 width=33) (actual time=0.931..0.932 rows=61 loops=3) Output: p.pool_name, p.client_id, p.pool_id Buckets: 1024 Batches: 1 Memory Usage: 12kB Buffers: shared hit=492 Worker 0: actual time=0.961..0.962 rows=61 loops=1 Buffers: shared hit=164 Worker 1: actual time=0.761..0.762 rows=61 loops=1 Buffers: shared hit=164 -> Seq Scan on public.pools p (cost=0.00..237.90 rows=63 width=33) (actual time=0.018..0.905 rows=61 loops=3) Output: p.pool_name, p.client_id, p.pool_id Filter: (p.client_id = 1) Rows Removed by Filter: 5682 Buffers: shared hit=492 Worker 0: actual time=0.022..0.931 rows=61 loops=1 Buffers: shared hit=164 Worker 1: actual time=0.018..0.738 rows=61 loops=1 Buffers: shared hit=164 -> Index Scan using user_prefs_pkey on public.user_prefs up (cost=0.42..3.74 rows=1 width=4) (actual time=0.090..0.090 rows=0 loops=61471) Output: up.user_id Index Cond: (up.user_id = u.user_id) Filter: (up.enable_public_leaderboards IS TRUE) Rows Removed by Filter: 1 Buffers: shared hit=241465 read=4579 dirtied=52 I/O Timings: read=5183.492 Worker 0: actual time=0.080..0.080 rows=0 loops=21799 Buffers: shared hit=85651 read=1608 dirtied=14 I/O Timings: read=1612.670 Worker 1: actual time=0.103..0.103 rows=0 loops=19986 Buffers: shared hit=78493 read=1497 dirtied=26 I/O Timings: read=1968.382 -> Index Only Scan using user_sessions_pkey on public.user_sessions us (cost=0.43..140.35 rows=155 width=8) (actual time=0.788..2.892 rows=73 loops=11640) Output: us.user_id, us.session_id Index Cond: ((us.user_id = u.user_id) AND (us.user_id IS NOT NULL)) Heap Fetches: 492751 Buffers: shared hit=497408 read=23315 I/O Timings: read=32931.842 Worker 0: actual time=0.774..2.781 rows=72 loops=4041 Buffers: shared hit=168459 read=7856 I/O Timings: read=10977.501 Worker 1: actual time=0.727..2.761 rows=72 loops=3960 Buffers: shared hit=166971 read=7593 I/O Timings: read=10688.224 Planning: Buffers: shared hit=101 Planning Time: 1.549 ms Execution Time: 13802.195 ms
Asked by DaveB (319 rep)
Mar 30, 2023, 03:29 PM
Last activity: Jul 24, 2025, 09:03 AM