PostgreSQL 10.6 – Partition’s Index Not Being Used

bitmap-indexexplainindex-tuningpostgresql

I'm truly stumped as to what's causing this issue and hoping for some guidance.

Firstly, this is in our STAGE environment and we partition this table based on the createdTime every month. I have triple checked the partitions and INDEXes on each and everything is Identical for every month. Also, our PRODUCTION database table I have run an EXPLAIN ANALYZE on the following query:

explain analyze select * from ubdrecord
where jsonb_extract_path_text("metadata",'deliveryNoteInfo','deliveryNoteNumber') =  '3535359152';

This results in the following result:

Append  (cost=0.43..23499.50 rows=21693 width=3503) (actual time=10.682..11.823 rows=7 loops=1)
  ->  Index Scan using p_01_2019_deliverynotenumberindex on ubdrecord_partition_01_2019  (cost=0.43..53.50 rows=47 width=765) (actual time=0.743..0.744 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_02_2019_deliverynotenumberindex on ubdrecord_partition_02_2019  (cost=0.43..34.23 rows=30 width=808) (actual time=0.892..0.893 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_03_2019_deliverynotenumberindex on ubdrecord_partition_03_2019  (cost=0.43..31.81 rows=28 width=800) (actual time=0.682..0.682 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_04_2019_deliverynotenumberindex on ubdrecord_partition_04_2019  (cost=0.43..37.17 rows=32 width=822) (actual time=0.904..0.904 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_05_2019_deliverynotenumberindex on ubdrecord_partition_05_2019  (cost=0.43..37.12 rows=33 width=827) (actual time=0.821..0.821 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_06_2019_deliverynotenumberindex on ubdrecord_partition_06_2019  (cost=0.43..50.06 rows=44 width=821) (actual time=0.720..0.720 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_07_2019_deliverynotenumberindex on ubdrecord_partition_07_2019  (cost=0.43..45.29 rows=40 width=816) (actual time=0.773..0.774 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_08_2019_deliverynotenumberindex on ubdrecord_partition_08_2019  (cost=0.43..37.82 rows=33 width=799) (actual time=0.950..0.950 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_09_2019_deliverynotenumberindex on ubdrecord_partition_09_2019  (cost=0.43..42.18 rows=37 width=843) (actual time=1.111..1.111 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_10_2019_deliverynotenumberindex on ubdrecord_partition_10_2019  (cost=0.43..44.22 rows=39 width=815) (actual time=0.765..0.765 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_11_2019_deliverynotenumberindex on ubdrecord_partition_11_2019  (cost=0.43..55.72 rows=49 width=738) (actual time=1.141..1.141 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_12_2019_deliverynotenumberindex on ubdrecord_partition_12_2019  (cost=0.43..37.24 rows=32 width=833) (actual time=0.720..0.720 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_01_2020_deliverynotenumberindex on ubdrecord_partition_01_2020  (cost=0.43..41.19 rows=36 width=814) (actual time=0.027..0.027 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_02_2020_deliverynotenumberindex on ubdrecord_partition_02_2020  (cost=0.43..39.26 rows=34 width=848) (actual time=0.027..0.027 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_03_2020_deliverynotenumberindex on ubdrecord_partition_03_2020  (cost=0.43..45.85 rows=40 width=856) (actual time=0.026..0.027 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_04_2020_deliverynotenumberindex on ubdrecord_partition_04_2020  (cost=0.43..3.77 rows=2 width=811) (actual time=0.025..0.026 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Bitmap Heap Scan on ubdrecord_partition_05_2020  (cost=241.19..22846.59 rows=21130 width=3575) (actual time=0.349..1.451 rows=7 loops=1)
        Recheck Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
        Heap Blocks: exact=7
        ->  Bitmap Index Scan on p_05_2020_deliverynotenumberindex  (cost=0.00..235.91 rows=21130 width=0) (actual time=0.338..0.338 rows=7 loops=1)
              Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_06_2020_deliverynotenumberindex on ubdrecord_partition_06_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.006..0.006 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_07_2020_deliverynotenumberindex on ubdrecord_partition_07_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.005..0.005 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_08_2020_deliverynotenumberindex on ubdrecord_partition_08_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.004..0.005 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_09_2020_deliverynotenumberindex on ubdrecord_partition_09_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.004..0.004 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_10_2020_deliverynotenumberindex on ubdrecord_partition_10_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.004..0.004 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_11_2020_deliverynotenumberindex on ubdrecord_partition_11_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.006..0.006 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
  ->  Index Scan using p_12_2020_deliverynotenumberindex on ubdrecord_partition_12_2020  (cost=0.14..2.36 rows=1 width=3575) (actual time=0.004..0.005 rows=0 loops=1)
        Index Cond: (jsonb_extract_path_text(metadata, VARIADIC '{deliveryNoteInfo,deliveryNoteNumber}'::text[]) = '3535359152'::text)
Planning time: 192.498 ms
Execution time: 11.997 ms

As you can see, the current month is not getting scanned like all the other months. There are two things distinctive about that month which is:

1) This is the current month we're in (hence getting a lot of writes to that table) and

2) This is the month that actually contains some results.

The reason I haven't explored these particular distinctions is because our Production environment is scanning the index perfectly fine for this month. I should point out the data in each environment and read/write patterns is also very similar. We've verified the partitions and indexes in both environments are identifical in their specific configuration but curious as to what other broader database parameter settings may be the cause of this discrepancy. Any insight would be greatly appreciated and I can provide any additional information you need, just ask.

UPDATE: The reason this is a problem for us is that the actual query we're running uses other where clause parameters (which are also indexed, although for this particular case far less efficient). It's not possible for us to remove the other indexes and again, in Production, the proper index is used and the query returns quickly. However in STG, failure to use the proper index results in the query not coming back for several minutes. I guess the follow up question would be how do we FORCE a query plan to use a specific index (if it's too difficult to determine exactly WHY it's not using it)? I hope I've been successful in explaining. Again, the DATA between the two environments are nearly identical.

Best Answer

Very likely your table statistics are outdated.

Try the following:

ANALYZE ubdrecord_partition_05_2020;

If that improves the estimate, you can reduce autovacuum_analyze_scale_factor for the partitions to have PostgreSQL calculate the statistics more often.