Hùng Phạm Việt
Reputation: 95
Query from GIN index of an array column too slow sometime
I am using PostgreSQL 12.5, I have a partitioned table tbl_message with some columns and I have a query to fetch data from that table
SELECT m.* FROM tbl_message m
WHERE m.hash IS NOT NULL AND m.involved_accounts @> array['account_id']::text[]
ORDER BY m.col1 DESC, m.col2 DESC, m.col3 DESC
LIMIT 25 OFFSET 0
About the columns
hash is NULLABLE TEXT
involved_accounts is TEXT[]
col1 is BIGINT NOT NULL
col2 is BIGINT NOT NULL
col3 is SMALLINT NOT NULL
I have indexes:
CREATE INDEX message_hash_index ON tbl_message(hash); -- for the first filter
CREATE INDEX message_involved_accounts_index ON tbl_message USING GIN(involved_accounts); -- for the second filter
CREATE INDEX message_order_index ON tbl_message(col1 desc, col2 desc, col3 desc); -- for the order
-- each of col1, col2, col3 also has their own index
The table at this moment has above 41 million records at time of wring and will keep increasing by ~12k records per day.
So when I perform the query which I wrote above, most of the query returns result after few milliseconds which is nice but with some account_id it takes 2-5 minutes and yes, it depends on the input param account_id even tho the account_id has the exactly same format and same length.
Some Query Plan:
16 secs to count
explain analyze select count(1) from message where hash is not null;
Finalize Aggregate (cost=7711827.60..7711827.61 rows=1 width=8) (actual time=13175.393..15703.182 rows=1 loops=1)
-> Gather (cost=7711827.18..7711827.59 rows=4 width=8) (actual time=13173.672..15703.160 rows=5 loops=1)
Workers Planned: 4
Workers Launched: 4
-> Partial Aggregate (cost=7710827.18..7710827.19 rows=1 width=8) (actual time=13150.783..13150.835 rows=1 loops=5)
-> Parallel Append (cost=0.56..7684791.29 rows=10414354 width=0) (actual time=187.908..12815.261 rows=8326720 loops=5)
-> Parallel Bitmap Heap Scan on message_16 (cost=904.65..47077.65 rows=17956 width=0) (actual time=208.622..330.643 rows=70319 loops=1)
Recheck Cond: (hash IS NOT NULL)
-> Bitmap Index Scan on message_16_hash_idx (cost=0.00..886.70 rows=71823 width=0) (actual time=19.628..19.628 rows=75445 loops=1)
Index Cond: (hash IS NOT NULL)
-> Parallel Index Only Scan using message_1_hash_idx on message_1 (cost=0.56..2390108.45 rows=3461250 width=0) (actual time=37.516..4434.148 rows=2768141 loops=5)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 7548376
-> Parallel Index Only Scan using message_2_hash_idx on message_2 (cost=0.56..2322145.34 rows=3050950 width=0) (actual time=68.249..5701.835 rows=4065667 loops=3)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 7338697
-> Parallel Index Only Scan using message_0_hash_idx on message_0 (cost=0.56..1693903.33 rows=2472619 width=0) (actual time=93.264..6489.499 rows=4946515 loops=2)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 5398655
-> Parallel Index Only Scan using message_3_hash_idx on message_3 (cost=0.56..1028833.21 rows=1171119 width=0) (actual time=0.101..4072.223 rows=2332674 loops=2)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 3156901
-> Parallel Index Only Scan using message_7_hash_idx on message_7 (cost=0.42..49070.09 rows=44645 width=0) (actual time=0.043..171.102 rows=138257 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 88474
-> Parallel Index Only Scan using message_5_hash_idx on message_5 (cost=0.42..29203.74 rows=29492 width=0) (actual time=0.039..77.370 rows=70787 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 42342
-> Parallel Index Only Scan using message_8_hash_idx on message_8 (cost=0.42..10828.02 rows=34819 width=0) (actual time=0.031..47.104 rows=84533 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 16210
-> Parallel Index Only Scan using message_14_hash_idx on message_14 (cost=0.42..1439.52 rows=38392 width=0) (actual time=0.021..24.691 rows=93447 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_13_hash_idx on message_13 (cost=0.42..1281.84 rows=34058 width=0) (actual time=0.022..18.290 rows=82294 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_11_hash_idx on message_11 (cost=0.42..1236.68 rows=33152 width=0) (actual time=0.018..16.634 rows=79022 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_12_hash_idx on message_12 (cost=0.42..1218.59 rows=32624 width=0) (actual time=0.022..16.128 rows=77633 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_15_hash_idx on message_15 (cost=0.42..1184.22 rows=30335 width=0) (actual time=0.018..18.168 rows=76143 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_9_hash_idx on message_9 (cost=0.42..1108.65 rows=29601 width=0) (actual time=0.026..14.513 rows=71693 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_10_hash_idx on message_10 (cost=0.42..1072.47 rows=28584 width=0) (actual time=0.065..13.795 rows=68969 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 0
-> Parallel Index Only Scan using message_6_hash_idx on message_6 (cost=0.42..27106.57 rows=26636 width=0) (actual time=0.055..71.713 rows=63436 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 39933
-> Parallel Index Only Scan using message_4_hash_idx on message_4 (cost=0.42..25901.16 rows=25408 width=0) (actual time=153.397..217.151 rows=60984 loops=1)
Index Cond: (hash IS NOT NULL)
Heap Fetches: 37519
Planning Time: 1.106 ms
JIT:
Functions: 187
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 4.864 ms, Inlining 168.951 ms, Optimization 400.175 ms, Emission 346.037 ms, Total 920.027 ms
Execution Time: 15704.360 ms
The query took 350s with account_id let say account_id_1
EXPLAIN ANALYZE SELECT m.* FROM message AS m
WHERE ((m.hash IS NOT NULL)) AND m.involved_accounts @> array['account_id_1']::text[]
ORDER BY m.col1 DESC, m.col2 DESC, m.col3 DESC
LIMIT 25 OFFSET 0;
Limit (cost=7.60..1047.21 rows=25 width=385) (actual time=336357.537..347776.125 rows=3 loops=1)
-> Merge Append (cost=7.60..13086668.58 rows=314704 width=385) (actual time=336357.535..347776.119 rows=3 loops=1)
Sort Key: m.col1 DESC, m.col2 DESC, m.col3 DESC
-> Index Scan using message_0_col1_col2_col3_idx on message_0 m (cost=0.43..2833000.49 rows=11544 width=387) (actual time=58029.607..58029.607 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 10423545
-> Index Scan using message_1_col1_col2_col3_idx on message_1 m_1 (cost=0.43..4014646.75 rows=47555 width=386) (actual time=92869.149..92869.149 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 14668913
-> Index Scan using message_2_col1_col2_col3_idx on message_2 m_2 (cost=0.43..3655774.25 rows=115975 width=384) (actual time=85838.196..85838.197 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 13940182
-> Index Scan using message_3_col1_col2_col3_idx on message_3 m_3 (cost=0.43..1481300.56 rows=64980 width=383) (actual time=40045.022..40045.022 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 6086597
-> Index Scan using message_4_col1_col2_col3_idx on message_4 m_4 (cost=0.42..61507.63 rows=4762 width=388) (actual time=3343.082..3343.082 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 490989
-> Index Scan using message_5_col1_col2_col3_idx on message_5 m_5 (cost=0.42..67689.29 rows=5429 width=388) (actual time=3268.888..3268.889 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 532991
-> Index Scan using message_6_col1_col2_col3_idx on message_6 m_6 (cost=0.42..57305.88 rows=5145 width=391) (actual time=2823.064..2823.064 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 437871
-> Index Scan using message_7_col1_col2_col3_idx on message_7 m_7 (cost=0.42..83700.77 rows=9928 width=400) (actual time=3580.900..3580.901 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 571980
-> Index Scan using message_8_col1_col2_col3_idx on message_8 m_8 (cost=0.42..81686.36 rows=7241 width=388) (actual time=2135.704..5567.318 rows=1 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 654258
-> Index Scan using message_9_col1_col2_col3_idx on message_9 m_9 (cost=0.42..88054.55 rows=5908 width=384) (actual time=6070.489..6070.489 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 784701
-> Index Scan using message_10_col1_col2_col3_idx on message_10 m_10 (cost=0.42..81750.93 rows=5481 width=384) (actual time=2397.042..5914.743 rows=1 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 727217
-> Index Scan using message_11_col1_col2_col3_idx on message_11 m_11 (cost=0.42..101345.12 rows=5739 width=381) (actual time=2499.117..6968.372 rows=1 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 921600
-> Index Scan using message_12_col1_col2_col3_idx on message_12 m_12 (cost=0.42..97795.14 rows=5269 width=382) (actual time=7395.400..7395.400 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 884379
-> Index Scan using message_13_col1_col2_col3_idx on message_13 m_13 (cost=0.42..93591.47 rows=5588 width=385) (actual time=6870.456..6870.456 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 826472
-> Index Scan using message_14_col1_col2_col3_idx on message_14 m_14 (cost=0.42..110115.43 rows=5559 width=381) (actual time=8402.985..8402.985 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 994695
-> Index Scan using message_15_col1_col2_col3_idx on message_15 m_15 (cost=0.42..88758.30 rows=4254 width=381) (actual time=6204.999..6204.999 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 788500
-> Index Scan using message_16_col1_col2_col3_idx on message_16 m_16 (cost=0.42..80640.09 rows=4347 width=385) (actual time=4583.407..4583.407 rows=0 loops=1)
Filter: ((hash IS NOT NULL) AND (involved_accounts @> '{account_id_1}'::text[]))
Rows Removed by Filter: 655792
Planning Time: 15.418 ms
Execution Time: 347776.246 ms
The query took only 33ms to execute when I changed the account id. You can see the query plan actually changed
Limit (cost=11574.91..11574.98 rows=25 width=386) (actual time=33.602..33.616 rows=25 loops=1)
-> Sort (cost=11574.91..11590.99 rows=6431 width=386) (actual time=33.600..33.612 rows=25 loops=1)
Sort Key: m.col1 DESC, m.col2 DESC, m.col3 DESC
Sort Method: quicksort Memory: 45kB
-> Append (cost=174.56..11393.43 rows=6431 width=386) (actual time=2.111..33.577 rows=32 loops=1)
-> Bitmap Heap Scan on message_0 m (cost=174.56..2492.36 rows=1981 width=387) (actual time=2.111..2.126 rows=4 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 1
Heap Blocks: exact=5
-> Bitmap Index Scan on message_0_involved_accounts_idx (cost=0.00..174.07 rows=2089 width=0) (actual time=2.095..2.096 rows=5 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_1 m_1 (cost=436.76..2339.70 rows=1618 width=386) (actual time=4.851..4.852 rows=1 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Heap Blocks: exact=1
-> Bitmap Index Scan on message_1_involved_accounts_idx (cost=0.00..436.35 rows=1714 width=0) (actual time=4.845..4.845 rows=1 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_2 m_2 (cost=272.40..3376.68 rows=2445 width=384) (actual time=3.159..3.231 rows=11 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 36
Heap Blocks: exact=43
-> Bitmap Index Scan on message_2_involved_accounts_idx (cost=0.00..271.79 rows=2799 width=0) (actual time=3.082..3.083 rows=47 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_3 m_3 (cost=307.83..759.88 rows=313 width=383) (actual time=3.596..3.596 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 35
Heap Blocks: exact=24
-> Bitmap Index Scan on message_3_involved_accounts_idx (cost=0.00..307.75 rows=407 width=0) (actual time=3.509..3.509 rows=37 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_4 m_4 (cost=244.45..281.07 rows=4 width=388) (actual time=3.003..3.003 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 14
Heap Blocks: exact=10
-> Bitmap Index Scan on message_4_involved_accounts_idx (cost=0.00..244.45 rows=33 width=0) (actual time=2.962..2.962 rows=14 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_5 m_5 (cost=469.97..509.92 rows=5 width=388) (actual time=5.837..5.868 rows=4 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 9
Heap Blocks: exact=12
-> Bitmap Index Scan on message_5_involved_accounts_idx (cost=0.00..469.97 rows=36 width=0) (actual time=5.818..5.818 rows=13 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_6 m_6 (cost=157.57..197.52 rows=5 width=391) (actual time=1.789..1.797 rows=1 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 13
Heap Blocks: exact=11
-> Bitmap Index Scan on message_6_involved_accounts_idx (cost=0.00..157.57 rows=36 width=0) (actual time=1.754..1.754 rows=14 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_7 m_7 (cost=185.16..238.43 rows=12 width=400) (actual time=2.097..2.105 rows=1 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 9
Heap Blocks: exact=6
-> Bitmap Index Scan on message_7_involved_accounts_idx (cost=0.00..185.16 rows=48 width=0) (actual time=2.076..2.077 rows=10 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_8 m_8 (cost=193.93..242.76 rows=6 width=388) (actual time=2.177..2.198 rows=3 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 19
Heap Blocks: exact=17
-> Bitmap Index Scan on message_8_involved_accounts_idx (cost=0.00..193.93 rows=44 width=0) (actual time=2.134..2.134 rows=22 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_9 m_9 (cost=4.79..62.50 rows=5 width=384) (actual time=0.073..0.081 rows=2 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 20
Heap Blocks: exact=15
-> Bitmap Index Scan on message_9_involved_accounts_idx (cost=0.00..4.79 rows=52 width=0) (actual time=0.027..0.027 rows=22 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_10 m_10 (cost=4.86..72.53 rows=6 width=384) (actual time=0.055..0.068 rows=1 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 18
Heap Blocks: exact=14
-> Bitmap Index Scan on message_10_involved_accounts_idx (cost=0.00..4.85 rows=61 width=0) (actual time=0.018..0.018 rows=19 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_11 m_11 (cost=4.86..72.55 rows=5 width=381) (actual time=0.039..0.049 rows=1 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 12
Heap Blocks: exact=8
-> Bitmap Index Scan on message_11_involved_accounts_idx (cost=0.00..4.86 rows=61 width=0) (actual time=0.018..0.018 rows=13 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_12 m_12 (cost=4.84..70.32 rows=5 width=382) (actual time=0.041..0.041 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 9
Heap Blocks: exact=5
-> Bitmap Index Scan on message_12_involved_accounts_idx (cost=0.00..4.84 rows=59 width=0) (actual time=0.020..0.020 rows=9 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_13 m_13 (cost=4.81..65.85 rows=5 width=385) (actual time=0.022..0.022 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 2
Heap Blocks: exact=1
-> Bitmap Index Scan on message_13_involved_accounts_idx (cost=0.00..4.81 rows=55 width=0) (actual time=0.017..0.017 rows=2 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_14 m_14 (cost=4.90..78.14 rows=6 width=381) (actual time=0.031..0.046 rows=3 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 7
Heap Blocks: exact=8
-> Bitmap Index Scan on message_14_involved_accounts_idx (cost=0.00..4.90 rows=66 width=0) (actual time=0.017..0.017 rows=10 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_15 m_15 (cost=4.80..63.61 rows=5 width=381) (actual time=0.037..0.037 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 7
Heap Blocks: exact=5
-> Bitmap Index Scan on message_15_involved_accounts_idx (cost=0.00..4.79 rows=53 width=0) (actual time=0.017..0.018 rows=7 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
-> Bitmap Heap Scan on message_16 m_16 (cost=388.63..437.46 rows=5 width=385) (actual time=4.446..4.446 rows=0 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_2}'::text[])
Filter: (hash IS NOT NULL)
Rows Removed by Filter: 3
Heap Blocks: exact=3
-> Bitmap Index Scan on message_16_involved_accounts_idx (cost=0.00..388.63 rows=44 width=0) (actual time=4.434..4.434 rows=3 loops=1)
Index Cond: (involved_accounts @> '{account_id_2}'::text[])
Planning Time: 2.543 ms
Execution Time: 33.921 ms
I also noticed the faster plan is only use Index Condition of involved_accounts and then filter the hash is not null later. I removed the condition hash is not null from query and it runs really fast.
Limit (cost=887468.62..887471.62 rows=25 width=419) (actual time=6709.798..7131.047 rows=25 loops=1)
-> Gather Merge (cost=887468.62..999118.78 rows=932480 width=419) (actual time=5084.627..5505.872 rows=25 loops=1)
Workers Planned: 4
Workers Launched: 4
-> Sort (cost=886468.57..887051.37 rows=233120 width=419) (actual time=5050.402..5050.438 rows=20 loops=5)
Sort Key: m_2.col123 DESC
Sort Method: top-N heapsort Memory: 47kB
Worker 0: Sort Method: top-N heapsort Memory: 50kB
Worker 1: Sort Method: top-N heapsort Memory: 47kB
Worker 2: Sort Method: top-N heapsort Memory: 44kB
Worker 3: Sort Method: top-N heapsort Memory: 46kB
-> Parallel Append (cost=551.27..879890.09 rows=233120 width=419) (actual time=1332.139..4917.573 rows=189949 loops=5)
-> Parallel Bitmap Heap Scan on message_2 m_2 (cost=991.69..132230.25 rows=30251 width=418) (actual time=859.916..2407.663 rows=65051 loops=2)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_2_involved_accounts_idx (cost=0.00..961.44 rows=121005 width=0) (actual time=39.265..39.266 rows=130102 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_16 m_16 (cost=809.64..36172.66 rows=9759 width=418) (actual time=1657.269..1890.565 rows=40724 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_16_involved_accounts_idx (cost=0.00..799.88 rows=39037 width=0) (actual time=24.626..24.626 rows=40724 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_3 m_3 (cost=745.03..97514.37 rows=22720 width=416) (actual time=1642.602..4089.925 rows=90358 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_3_involved_accounts_idx (cost=0.00..722.31 rows=90881 width=0) (actual time=23.948..23.949 rows=90358 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_9 m_9 (cost=551.27..56916.12 rows=16790 width=418) (actual time=1634.792..1905.398 rows=66960 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_9_involved_accounts_idx (cost=0.00..534.48 rows=67158 width=0) (actual time=18.669..18.669 rows=66960 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_11 m_11 (cost=546.24..58071.66 rows=16627 width=415) (actual time=15.659..1026.270 rows=66403 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_11_involved_accounts_idx (cost=0.00..529.61 rows=66508 width=0) (actual time=8.589..8.590 rows=66403 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_14 m_14 (cost=492.64..54205.42 rows=15004 width=415) (actual time=21.116..1559.622 rows=60123 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_14_involved_accounts_idx (cost=0.00..477.64 rows=60018 width=0) (actual time=13.919..13.919 rows=60123 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_12 m_12 (cost=463.37..50438.38 rows=14096 width=416) (actual time=18.859..1621.024 rows=57992 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_12_involved_accounts_idx (cost=0.00..449.27 rows=56383 width=0) (actual time=12.007..12.008 rows=57992 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Parallel Bitmap Heap Scan on message_13 m_13 (cost=460.58..49813.39 rows=14006 width=419) (actual time=20.554..1259.837 rows=54899 loops=1)
Recheck Cond: (involved_accounts @> '{account_id_1}'::text[])
-> Bitmap Index Scan on message_13_involved_accounts_idx (cost=0.00..446.57 rows=56023 width=0) (actual time=13.220..13.220 rows=54899 loops=1)
Index Cond: (involved_accounts @> '{account_id_1}'::text[])
Planning Time: 21.657 ms
JIT:
Functions: 342
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 36.420 ms, Inlining 220.761 ms, Optimization 5049.366 ms, Emission 2849.535 ms, Total 8156.083 ms
Execution Time: 7157.161 ms
Due to limitation in characters of SOF, I remove some lines when scanning partitioned table. The message table currently has 16 sub-tables
Thank you for your time
Upvotes: 0
Views: 521
Answers (1)
jjanes
Reputation: 44147
I don't know what you meant by "Expect 3 rows found, actual 25 rows", that sounds like your middle plan (only backwards), not one of simpler ones I asked for and without the LIMIT.
But based on the three plans you have shown, I think I can put together the picture. The vast majority of rows have hash IS NOT NULL. But the specific case of rows associated with 'account_id_1', the vast majority have hash IS NULL. This leads to poor row estimates, which in turn leads to a poor plan.
This is the kind of thing that could generally be fixed by extended statistics covering both hash and involved_accounts, but not in this case. IS NOT NULL does not refer to a specific value, so can't be covered by the extended statistics. And involved_accounts is an array column, and those also are not well covered by extended statistics.
You could use extended statistics on an expression, introduced in v14:
create statistics h_and_ia on (hash is not null and involved_accounts@>ARRAY['account_id_1']) from j;
But the problem is that that extended statistics only gets picked if you write the query in a rather unnatural way:
WHERE (hash is not null and involved_accounts@>ARRAY['account_id_1']) IS TRUE
And if you are going to write it in an unnatural way, you might as well target (for disabling) the ORDER BY index specifically, by changing the order by:
ORDER BY m.col1+0 DESC, m.col2 DESC, m.col3 DESC
Or of course drop that index, if you doesn't serve any other purpose.
Upvotes: 1
Related Questions
- How does one query a postgres array using the gin index?
- postgres: why does this GIN index not used for this "object in array" query
- GIN index on array column not used, even after setting `enable_seqscan` to off?
- How to use GIN index with array column in postgresql?
- How to optimize query if I already use GIN index
- postgres: why isn't this query using the GIN index on the array value?
- PostgreSQL array_agg panfully slow
- PostgreSQL GIN indexes on arrays
- GIN index not used for small table when 0 rows returned
- Postgresql very slow query on indexed column