1

I have a query:

WITH route_ids_filtered_by_shipments AS (
    SELECT DISTINCT
        rts.route_id
    FROM
        route_to_shipment rts
    JOIN
        shipment s
            ON rts.shipment_id = s.shipment_id
    WHERE
        s.store_sender_id = ANY('{"a2342659-5f2f-11eb-85a3-1c34dae33151","7955ab25-0511-11ee-885e-08c0eb32014b","319ce173-2614-11ee-b10a-08c0eb31fffb","4bdddeb3-5ec9-11ee-b10a-08c0eb31fffb","8e6054c5-6db3-11ea-9786-0050560307be","485dc39c-debc-11ed-885e-08c0eb32014b","217d0f7b-78de-11ea-a214-0050560307be","a5a8a21a-9b9a-11ec-b0fc-08c0eb31fffb","79e7d5be-ef8b-11eb-a0ee-ec0d9a21b021","3f35d68a-1212-11ec-85ad-1c34dae33151","087bcf22-5f30-11eb-85a3-1c34dae33151","c065e1c8-a679-11eb-85a9-1c34dae33151"}'::uuid[])
)
SELECT
    r.acceptance_status
,   count(*) count
FROM
    route r
JOIN
    route_ids_filtered_by_shipments rifs
        ON r.route_id = rifs.route_id
WHERE
    r.acceptance_status <> 'ERRORED'::route_acceptance_status
GROUP BY
    r.acceptance_status;

Its execution plan (obtained via EXPLAIN (ANALYZE, BUFFERS, SETTINGS):

HashAggregate  (cost=579359.05..579359.09 rows=4 width=12) (actual time=6233.281..6669.596 rows=3 loops=1)
  Group Key: r.acceptance_status
  Batches: 1  Memory Usage: 24kB
  Buffers: shared hit=14075979 read=573570
  I/O Timings: shared/local read=19689.039
  ->  Hash Join  (cost=564249.11..578426.89 rows=186432 width=4) (actual time=6064.176..6658.862 rows=69460 loops=1)
        Hash Cond: (r.route_id = rts.route_id)
        Buffers: shared hit=14075979 read=573570
        I/O Timings: shared/local read=19689.039
        ->  Seq Scan on route r  (cost=0.00..13526.16 rows=248230 width=20) (actual time=0.015..112.580 rows=248244 loops=1)
              Filter: (acceptance_status <> 'ERRORED'::route_acceptance_status)
              Rows Removed by Filter: 7879
              Buffers: shared hit=5112 read=3492
              I/O Timings: shared/local read=35.687
        ->  Hash  (cost=561844.75..561844.75 rows=192349 width=16) (actual time=6063.413..6499.725 rows=69460 loops=1)
              Buckets: 262144  Batches: 1  Memory Usage: 5304kB
              Buffers: shared hit=14070867 read=570078
              I/O Timings: shared/local read=19653.352
              ->  HashAggregate  (cost=557997.77..559921.26 rows=192349 width=16) (actual time=6038.518..6487.332 rows=69460 loops=1)
                    Group Key: rts.route_id
                    Batches: 1  Memory Usage: 10257kB
                    Buffers: shared hit=14070867 read=570078
                    I/O Timings: shared/local read=19653.352
                    ->  Gather  (cost=1001.02..555707.18 rows=916234 width=16) (actual time=0.976..6341.587 rows=888024 loops=1)
                          Workers Planned: 7
                          Workers Launched: 7
                          Buffers: shared hit=14070867 read=570078
                          I/O Timings: shared/local read=19653.352
                          ->  Nested Loop  (cost=1.02..463083.78 rows=130891 width=16) (actual time=1.576..5990.903 rows=111003 loops=8)
                                Buffers: shared hit=14070867 read=570078
                                I/O Timings: shared/local read=19653.352
                                ->  Parallel Index Only Scan using route_to_shipment_pkey on route_to_shipment rts  (cost=0.56..78746.01 rows=517565 width=32) (actual time=0.050..733.728 rows=452894 loops=8)
                                      Heap Fetches: 401042
                                      Buffers: shared hit=94576 read=38851
                                      I/O Timings: shared/local read=2255.435
                                ->  Index Scan using shipment_pkey on shipment s  (cost=0.46..0.74 rows=1 width=16) (actual time=0.011..0.011 rows=0 loops=3623151)
                                      Index Cond: (shipment_id = rts.shipment_id)
"                                      Filter: (store_sender_id = ANY ('{a2342659-5f2f-11eb-85a3-1c34dae33151,7955ab25-0511-11ee-885e-08c0eb32014b,319ce173-2614-11ee-b10a-08c0eb31fffb,4bdddeb3-5ec9-11ee-b10a-08c0eb31fffb,8e6054c5-6db3-11ea-9786-0050560307be,485dc39c-debc-11ed-885e-08c0eb32014b,217d0f7b-78de-11ea-a214-0050560307be,a5a8a21a-9b9a-11ec-b0fc-08c0eb31fffb,79e7d5be-ef8b-11eb-a0ee-ec0d9a21b021,3f35d68a-1212-11ec-85ad-1c34dae33151,087bcf22-5f30-11eb-85a3-1c34dae33151,c065e1c8-a679-11eb-85a9-1c34dae33151}'::uuid[]))"
                                      Rows Removed by Filter: 1
                                      Buffers: shared hit=13976291 read=531227
                                      I/O Timings: shared/local read=17397.917
"Settings: effective_cache_size = '256GB', effective_io_concurrency = '250', max_parallel_workers = '24', max_parallel_workers_per_gather = '8', random_page_cost = '1', seq_page_cost = '1.2', work_mem = '128MB'"
Planning:
  Buffers: shared hit=16
Planning Time: 0.409 ms
Execution Time: 6670.976 ms

My task it to make query be executed within 1 sec, at least. I can observe in the plan(basing on my current knowledge about PG query optimization) that some nodes have a high number of heap fetches and it could be cured with VACCUM on a table. What I'm trying to comprehend:

  1. Why PG chose join's ON predicate rts.shipment_id = shipment_id as a base for building set of rows and performed filtering by store_sender_id over that set if there is a separate index on the shipment.store_sender_id column which is highly selective. In my understanding, to find a relative small number of rows matched by store_sender_idand filter by rts.shipment_id = shipment_id would be a waaaay faster. Or there could be union of bitmap index scans (via BitmapAnd).
  2. Index Scan using shipment_pkey on shipment s (cost=0.46..0.74 rows=1 width=16) (actual time=0.011..0.011 rows=0 loops=3623151)

If I multiply actual total time by loops counter to get actual time I get near 40 sec, when the query completes within 7 sec. How could it be???

4
  • Here's the more readable explain analyze on depesz
    – bobflux
    Dec 16, 2023 at 8:35
  • 1
    Can you please show exact index definitions? Also post EXPLAIN ANALYZE for: SELECT DISTINCT shipment_id FROM shipment s WHERE s.store_sender_id = ANY(your big list)
    – bobflux
    Dec 16, 2023 at 8:58
  • 4
    Having random_page_cost set to lower than seq_page_cost is totally insane. Of course it will lead to demented plans.
    – jjanes
    Dec 16, 2023 at 13:45
  • "If I multiply actual total time by loops counter to get actual time I get near 40 sec, when the query completes within 7 sec." You have 8 parallel processes. It only takes 5 seconds of clock time for them to spend 40 seconds doing something.
    – jjanes
    Dec 16, 2023 at 13:51

1 Answer 1

3

The index scan is taking a long time because

  1. it is repeated very often

  2. there are not enough index columns, so PostgreSQL has to fetch the table rows.

Try this index:

CREATE INDEX ON shipment (shipment_id, store_sender_id);
VACUUM shipment;

Frequent VACUUM is required to keep the index-only scan efficient.

2
  • Thanks a lot, I'll try it. Do you have any idea, why planner totally ignore separate index on store_sender_id? I expected that there will be bitmap scan or something :( Dec 16, 2023 at 13:54
  • Probably because it would have been even slower. Dec 16, 2023 at 19:38

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.