The table consists of ~2.1 million rows, of which most (i.e. deleted = false) have an __identifier column with a shape of {00000000-0000-0000-0000-000000000000,<unique_uuid>} while the rest, i.e. deleted = true have NULL in the __identifier column.
medplum=# select deleted, count(*) from "ServiceRequest" group by deleted;
deleted | count
---------+---------
f | 2109903
t | 12429
(2 rows)
medplum=# select id, __identifier from "ServiceRequest" where deleted = false limit 3;
id | __identifier
--------------------------------------+-----------------------------------------------------------------------------
6e5c06b2-ec60-4323-9cb9-b47a0495215b | {00000000-0000-0000-0000-000000000000,6e5c06b2-ec60-4323-9cb9-b47a0495215b}
0197e64d-ffed-734d-9452-1cc186b71dd5 | {00000000-0000-0000-0000-000000000000,0197e64d-ffed-734d-9452-1cc186b71dd5}
0d974fd8-7633-4b70-a83c-9f83e8b470df | {00000000-0000-0000-0000-000000000000,0d974fd8-7633-4b70-a83c-9f83e8b470df}
(3 rows)
Time: 0.665 ms
medplum=# select id, __identifier from "ServiceRequest" where deleted = true limit 3;
id | __identifier
--------------------------------------+--------------
a305e665-cda2-4307-a476-bc991ccd34e7 | (null)
fb0440b4-f94f-4310-9e8b-1a37df9e7cef | (null)
8e2ab208-c6a3-45de-b4f9-b68f3b6cda92 | (null)
The stats on the __identifier column. Notice the mce array consists entirely of {00000000-0000-0000-0000-000000000000} and the most_common_elem_freqs is {1,1,1,0}.
medplum=# analyze "ServiceRequest";
ANALYZE
Time: 20499.917 ms (00:20.500)
medplum=# SELECT
tablename,
attname,
n_distinct,
null_frac,
array_length(most_common_elems, 1) as mce_count,
(most_common_elems::text::uuid[])[1:5] as mce_head,
(most_common_elems::text::uuid[])[array_length(most_common_elems,1)-5:array_length(most_common_elems,1)] as mce_tail,
most_common_elem_freqs[1:5] as mce_freqs_head,
most_common_elem_freqs[array_upper(most_common_elem_freqs,1)-5:array_upper(most_common_elem_freqs,1)] as mce_freqs_tail
FROM pg_stats
WHERE tablename in ('ServiceRequest') AND attname in ('__identifier');
tablename | attname | n_distinct | null_frac | mce_count | mce_head | mce_tail | mce_freqs_head | mce_freqs_tail
----------------+--------------+------------+--------------+-----------+----------------------------------------+----------------------------------------+----------------+----------------
ServiceRequest | __identifier | -0.9944133 | 0.0055866665 | 1 | {00000000-0000-0000-0000-000000000000} | {00000000-0000-0000-0000-000000000000} | {1,1,1,0} | {1,1,1,0}
(1 row)
Time: 3.183 ms
Run the problematic query with an empty GIN pending list. The optimal query plan is used with a cost of 68 despite the inaccurate row estimate of 10,551 versus the actual zero.
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=68.34..72.05 rows=3 width=176) (actual time=0.046..0.047 rows=0 loops=1)
Buffers: shared hit=1 read=4
I/O Timings: shared read=0.018
-> Bitmap Heap Scan on "ServiceRequest" (cost=68.34..11613.38 rows=9338 width=176) (actual time=0.045..0.045 rows=0 loops=1)
Recheck Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Filter: ((NOT deleted) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Buffers: shared hit=1 read=4
I/O Timings: shared read=0.018
-> Bitmap Index Scan on "ServiceRequest___idnt_idx" (cost=0.00..66.00 rows=10551 width=0) (actual time=0.043..0.043 rows=0 loops=1)
Index Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Buffers: shared hit=1 read=4
I/O Timings: shared read=0.018
Planning:
Buffers: shared hit=187 read=74
I/O Timings: shared read=0.398
Planning Time: 1.784 ms
Execution Time: 0.105 ms
(17 rows)
Time: 3.427 ms
Fill the pending list to 333 pages (2.6MB) to simulate regular inserts/updates on the table.
medplum=# WITH to_update as (SELECT id from "ServiceRequest" WHERE deleted = false ORDER BY random() LIMIT 120000)
update "ServiceRequest" as res set __identifier = ARRAY['00000000-0000-0000-0000-000000000000',res.id]::UUID[] FROM to_update WHERE res.id = to_update.id;
UPDATE 120000
Time: 8313.401 ms (00:08.313)
medplum=# SELECT
n.nspname as schema_name,
t.relname as table_name,
i.relname as index_name,
i.reloptions as index_options,
coalesce((SELECT (regexp_matches(coalesce(quote_ident(opt), ''), 'fastupdate=(\\w+)'))[1]::boolean FROM unnest(coalesce(i.reloptions, '{}')) AS opt
WHERE opt ~ '^fastupdate='), TRUE) AS fastupdate,
(SELECT (regexp_matches(coalesce(quote_ident(opt), ''), 'gin_pending_list_limit=(\\d+)'))[1]::INT FROM unnest(coalesce(i.reloptions, '{}')) AS opt
WHERE opt ~ '^gin_pending_list_limit=') AS gin_pending_list_limit,
pg_size_pretty((gm.n_pending_pages::int * current_setting('block_size')::int)::bigint) as pretty_n_bytes_pending,
gm.n_pending_pages::int * current_setting('block_size')::int as n_bytes_pending,
gm.n_pending_pages as n_pending_pages,
gm.n_pending_tuples as n_pending_tuples,
gm.n_total_pages as n_total_pages,
gm.n_entry_pages as n_entry_pages,
gm.n_data_pages as n_data_pages,
gm.n_entries as n_entries,
gm.version as version
FROM pg_index ix
JOIN pg_class i ON ix.indexrelid = i.oid
JOIN pg_class t ON ix.indrelid = t.oid
JOIN pg_namespace AS n ON n.oid = t.relnamespace
JOIN pg_am a ON i.relam = a.oid
CROSS JOIN LATERAL gin_metapage_info(get_raw_page(quote_ident(i.relname), 0)) AS gm
WHERE a.amname = 'gin'
AND n.nspname = 'public'
AND t.relname IN ('ServiceRequest')
ORDER BY table_name, index_name;
schema_name | table_name | index_name | index_options | fastupdate | gin_pending_list_limit | pretty_n_bytes_pending | n_bytes_pending | n_pending_pages | n_pending_tuples | n_total_pages | n_entry_pages | n_data_pages | n_entries | version
-------------+----------------+---------------------------+---------------+------------+------------------------+------------------------+-----------------+-----------------+------------------+---------------+---------------+--------------+-----------+---------
public | ServiceRequest | ServiceRequest___idnt_idx | (null) | t | (null) | 2664 kB | 2727936 | 333 | 48172 | 94816 | 92542 | 854 | 13995798 | 2
(1 row)
Now sequential scan is chosen with cost 227.66. Note the row estimate of 9338 versus the actual 0.
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=0.00..227.66 rows=3 width=176) (actual time=2279.554..2279.556 rows=0 loops=1)
Buffers: shared hit=676797 dirtied=111047
-> Seq Scan on "ServiceRequest" (cost=0.00..708642.81 rows=9338 width=176) (actual time=2279.552..2279.552 rows=0 loops=1)
Filter: ((NOT deleted) AND (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[]) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Rows Removed by Filter: 2122332
Buffers: shared hit=676797 dirtied=111047
Planning:
Buffers: shared hit=1
Planning Time: 0.109 ms
Execution Time: 2279.579 ms
(10 rows)
Increase effective_cache_size from 4GB to 96GB. Now the ServiceRequest_projectId_idx index is used instead of a sequential scan with a cost of 223.77.
medplum=# set effective_cache_size = '96GB';
SET
Time: 0.338 ms
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=0.43..223.77 rows=3 width=176) (actual time=1869.419..1869.420 rows=0 loops=1)
Buffers: shared hit=406279 read=3423 dirtied=212
I/O Timings: shared read=22.041
-> Index Scan using "ServiceRequest_projectId_idx" on "ServiceRequest" (cost=0.43..695185.39 rows=9338 width=176) (actual time=1869.417..1869.418 rows=0 loops=1)
Index Cond: ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid)
Filter: ((NOT deleted) AND (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[]))
Rows Removed by Filter: 1891946
Buffers: shared hit=406279 read=3423 dirtied=212
I/O Timings: shared read=22.041
Planning:
Buffers: shared hit=1
Planning Time: 0.109 ms
Execution Time: 1869.447 ms
(13 rows)
Time: 1870.099 ms (00:01.870)
Remove ServiceRequest_projectId_idx to see the next best option. Back to sequential scan with the same cost of 227.66.
medplum=# BEGIN;
BEGIN
Time: 0.293 ms
medplum=*# DROP INDEX "ServiceRequest_projectId_idx"
medplum-*# ;
DROP INDEX
Time: 1.059 ms
medplum=*# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=0.00..227.66 rows=3 width=176) (actual time=1773.287..1773.289 rows=0 loops=1)
Buffers: shared hit=676797
-> Seq Scan on "ServiceRequest" (cost=0.00..708642.81 rows=9338 width=176) (actual time=1773.285..1773.286 rows=0 loops=1)
Filter: ((NOT deleted) AND (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[]) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Rows Removed by Filter: 2122332
Buffers: shared hit=676797
Planning:
Buffers: shared hit=5
Planning Time: 0.144 ms
Execution Time: 1773.312 ms
(10 rows)
Time: 1774.091 ms (00:01.774)
Penalize sequential scan. Now the ServiceRequest_projectId_lastUpdated_idx index is used with a cost of 241.88
medplum=*# set enable_seqscan = off;
SET
Time: 0.290 ms
medplum=*# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=0.43..241.88 rows=3 width=176) (actual time=2783.302..2783.303 rows=0 loops=1)
Buffers: shared hit=1363841 read=2016 dirtied=18177
I/O Timings: shared read=16.374
-> Index Scan using "ServiceRequest_projectId_lastUpdated_idx" on "ServiceRequest" (cost=0.43..751560.07 rows=9338 width=176) (actual time=2783.300..2783.301 rows=0 loops=1)
Index Cond: ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid)
Filter: ((NOT deleted) AND (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[]))
Rows Removed by Filter: 1891946
Buffers: shared hit=1363841 read=2016 dirtied=18177
I/O Timings: shared read=16.374
Planning:
Buffers: shared hit=1
Planning Time: 0.112 ms
Execution Time: 2783.335 ms
(13 rows)
Time: 2783.976 ms (00:02.784)
Drop that index too to see the next best plan. Once again the optimal plan using the ServiceRequest___idnt_idx index is chosen with a cost of 517; more than double the previous plan's estimated cost. Why? The estimate for the Bitmap Index Scan is very high (515.55) since all 333 pages of the pending list must be scanned.
medplum=*# DROP INDEX "ServiceRequest_projectId_lastUpdated_idx";
DROP INDEX
Time: 0.506 ms
medplum=*# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=517.89..521.60 rows=3 width=176) (actual time=4.863..4.864 rows=0 loops=1)
Buffers: shared hit=338
-> Bitmap Heap Scan on "ServiceRequest" (cost=517.89..12062.93 rows=9338 width=176) (actual time=4.861..4.861 rows=0 loops=1)
Recheck Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Filter: ((NOT deleted) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Buffers: shared hit=338
-> Bitmap Index Scan on "ServiceRequest___idnt_idx" (cost=0.00..515.55 rows=10551 width=0) (actual time=4.858..4.858 rows=0 loops=1)
Index Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Buffers: shared hit=338
Planning:
Buffers: shared hit=5
Planning Time: 0.133 ms
Execution Time: 4.888 ms
(13 rows)
Time: 5.526 ms
Clean the GIN pending list. The cost for the same ServiceRequest___idnt_idx plan dropped from 517 back to the original 68 since there now aren't 333 pages of the pending list to scan.
medplum=*# SELECT gin_clean_pending_list('"ServiceRequest___idnt_idx"');
gin_clean_pending_list
------------------------
333
(1 row)
Time: 535.600 ms
medplum=*# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=68.34..72.05 rows=3 width=176) (actual time=0.016..0.017 rows=0 loops=1)
Buffers: shared hit=5
-> Bitmap Heap Scan on "ServiceRequest" (cost=68.34..11613.38 rows=9338 width=176) (actual time=0.015..0.015 rows=0 loops=1)
Recheck Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Filter: ((NOT deleted) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Buffers: shared hit=5
-> Bitmap Index Scan on "ServiceRequest___idnt_idx" (cost=0.00..66.00 rows=10551 width=0) (actual time=0.013..0.013 rows=0 loops=1)
Index Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Buffers: shared hit=5
Planning:
Buffers: shared hit=1
Planning Time: 0.096 ms
Execution Time: 0.040 ms
(13 rows)
Time: 0.589 ms
The patch: v2-0001-Track-the-maximum-possible-frequency-of-non-MCE-a.patch
Fill the pending list back to roughly the same size: 2.7MB (336 pages) to once again simulate regular inserts/updates on the table.
medplum=# WITH to_update as (SELECT id from "ServiceRequest" WHERE deleted = false ORDER BY random() LIMIT 120000)
update "ServiceRequest" as res set __identifier = ARRAY['00000000-0000-0000-0000-000000000000',res.id]::UUID[] FROM to_update WHERE res.id = to_update.id;
UPDATE 120000
Time: 8313.574 ms (00:08.314)
medplum=# SELECT
n.nspname as schema_name,
t.relname as table_name,
i.relname as index_name,
i.reloptions as index_options,
coalesce((SELECT (regexp_matches(coalesce(quote_ident(opt), ''), 'fastupdate=(\\w+)'))[1]::boolean FROM unnest(coalesce(i.reloptions, '{}')) AS opt
WHERE opt ~ '^fastupdate='), TRUE) AS fastupdate,
(SELECT (regexp_matches(coalesce(quote_ident(opt), ''), 'gin_pending_list_limit=(\\d+)'))[1]::INT FROM unnest(coalesce(i.reloptions, '{}')) AS opt
WHERE opt ~ '^gin_pending_list_limit=') AS gin_pending_list_limit,
pg_size_pretty((gm.n_pending_pages::int * current_setting('block_size')::int)::bigint) as pretty_�[48;79;487;1343;3409tn_bytes_pending,
gm.n_pending_pages::int * current_setting('block_size')::int as n_bytes_pending,
gm.n_pending_pages as n_pending_pages,
gm.n_pending_tuples as n_pending_tuples,
gm.n_total_pages as n_total_pages,
gm.n_entry_pages as n_entry_pages,
gm.n_data_pages as n_data_pages,
gm.n_entries as n_entries,
gm.version as version
FROM pg_index ix
JOIN pg_class i ON ix.indexrelid = i.oid
JOIN pg_class t ON ix.indrelid = t.oid
JOIN pg_namespace AS n ON n.oid = t.relnamespace
JOIN pg_am a ON i.relam = a.oid
CROSS JOIN LATERAL gin_metapage_info(get_raw_page(quote_ident(i.relname), 0)) AS gm
WHERE a.amname = 'gin'
AND n.nspname = 'public'
AND t.relname IN ('ServiceRequest')
ORDER BY table_name, index_name;
schema_name | table_name | index_name | index_options | fastupdate | gin_pending_list_limit | pretty_n_bytes_pending | n_bytes_pending | n_pending_pages | n_pending_tuples | n_total_pages | n_entry_pages | n_data_pages | n_entries | version
-------------+----------------+---------------------------+---------------+------------+------------------------+------------------------+-----------------+-----------------+------------------+---------------+---------------+--------------+-----------+---------
public | ServiceRequest | ServiceRequest___idnt_idx | (null) | t | (null) | 2688 kB | 2752512 | 336 | 48688 | 94816 | 92542 | 854 | 13995798 | 2
(1 row)
Still sequential scan
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=0.00..227.66 rows=3 width=176) (actual time=1817.978..1817.980 rows=0 loops=1)
Buffers: shared hit=676797 dirtied=12285
-> Seq Scan on "ServiceRequest" (cost=0.00..708642.81 rows=9338 width=176) (actual time=1817.976..1817.977 rows=0 loops=1)
Filter: ((NOT deleted) AND (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[]) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Rows Removed by Filter: 2122332
Buffers: shared hit=676797 dirtied=12285
Planning:
Buffers: shared hit=25 read=41
I/O Timings: shared read=0.242
Planning Time: 0.634 ms
Execution Time: 1818.018 ms
(11 rows)
Time: 1819.498 ms (00:01.819)
Analyze the table to realize the effects of the patch. Notice the mce array still consists entirely of {00000000-0000-0000-0000-000000000000}, but the most_common_elem_freqs is {1,1.3412692e-05,1,0} versus the previous, unpatched {1,1,1,0}.
medplum=# analyze "ServiceRequest";
ANALYZE
Time: 19172.471 ms (00:19.172)
medplum=# SELECT
tablename,
attname,
n_distinct,
null_frac,
array_length(most_common_elems, 1) as mce_count,
(most_common_elems::text::uuid[])[1:5] as mce_head,
(most_common_elems::text::uuid[])[array_length(most_common_elems,1)-5:array_length(most_common_elems,1)] as mce_tail,
most_common_elem_freqs[1:5] as mce_freqs_head,
most_common_elem_freqs[array_upper(most_common_elem_freqs,1)-5:array_upper(most_common_elem_freqs,1)] as mce_freqs_tail
FROM pg_stats
WHERE tablename in ('ServiceRequest') AND attname in ('__identifier');
tablename | attname | n_distinct | null_frac | mce_count | mce_head | mce_tail | mce_freqs_head | mce_freqs_tail
----------------+--------------+-------------+--------------+-----------+----------------------------------------+----------------------------------------+-----------------------+-----------------------
ServiceRequest | __identifier | -0.99408334 | 0.0059166667 | 1 | {00000000-0000-0000-0000-000000000000} | {00000000-0000-0000-0000-000000000000} | {1,1.3412692e-05,1,0} | {1,1.3412692e-05,1,0}
(1 row)
As a result, the ideal ServiceRequest___idnt_idx index is immediately used with a cost of 463. Notice the much more accurate row estimate of 28 versus the previous, unpatched estimate of ~10,000. None of the previous, invasive steps were needed to arrive at the optimal query plan, which included:
- increasing
effective_cache_sizefrom4GBto96GB - disabling sequential scans with
set enable_seqscan = off; - dropping two other indexes
ServiceRequest_projectId_idxandServiceRequest_projectId_lastUpdated_idx - cleaning/disabling the GIN pending list
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=463.32..467.06 rows=3 width=175) (actual time=4.887..4.888 rows=0 loops=1)
Buffers: shared hit=337 read=4
I/O Timings: shared read=0.035
-> Bitmap Heap Scan on "ServiceRequest" (cost=463.32..494.52 rows=25 width=175) (actual time=4.886..4.886 rows=0 loops=1)
Recheck Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Filter: ((NOT deleted) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Buffers: shared hit=337 read=4
I/O Timings: shared read=0.035
-> Bitmap Index Scan on "ServiceRequest___idnt_idx" (cost=0.00..463.31 rows=28 width=0) (actual time=4.883..4.883 rows=0 loops=1)
Index Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Buffers: shared hit=337 read=4
I/O Timings: shared read=0.035
Planning:
Buffers: shared hit=99
Planning Time: 0.520 ms
Execution Time: 4.919 ms
(16 rows)
Time: 6.087 ms
Cleaning the GIN pending list still is of course very beneficial. The cost drop from 463 to nine; buffers read drops from 341 (337+4) to 5. The number of pending list pages cleaned (336) perfectly accounts for the delta.
medplum=# SELECT gin_clean_pending_list('"ServiceRequest___idnt_idx"');
gin_clean_pending_list
------------------------
336
(1 row)
Time: 531.398 ms
medplum=# EXPLAIN (ANALYZE, BUFFERS) SELECT id, content, "lastUpdated" from "ServiceRequest" WHERE deleted = false AND "projectId" IN ('0b6d21e8-2e4d-4d8d-81ba-c224f02afccf') AND __identifier @> ARRAY['00000000-0000-0000-0000-000000000001']::UUID[] LIMIT 3;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=9.72..13.46 rows=3 width=175) (actual time=0.019..0.019 rows=0 loops=1)
Buffers: shared hit=5
-> Bitmap Heap Scan on "ServiceRequest" (cost=9.72..40.92 rows=25 width=175) (actual time=0.018..0.018 rows=0 loops=1)
Recheck Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Filter: ((NOT deleted) AND ("projectId" = '0b6d21e8-2e4d-4d8d-81ba-c224f02afccf'::uuid))
Buffers: shared hit=5
-> Bitmap Index Scan on "ServiceRequest___idnt_idx" (cost=0.00..9.71 rows=28 width=0) (actual time=0.015..0.015 rows=0 loops=1)
Index Cond: (__identifier @> '{00000000-0000-0000-0000-000000000001}'::uuid[])
Buffers: shared hit=5
Planning:
Buffers: shared hit=1
Planning Time: 0.124 ms
Execution Time: 0.046 ms
(13 rows)
Time: 0.757 ms