I have two servers, one running Postgres 11, the other Postgres 13. Both servers have the same amount of RAM and CPU cores/speeds, and both are configured to these parameters. I have a query which on Postgres 13 is noticeably slower than on Postgres 11 (the difference is only 1 second, but that's a ~40% increase, and this ends up being noticeable in my app which executes the query multiple times).
Here is the query:
SELECT *
FROM orders_view
ORDER BY orderdate DESC, order_id DESC
LIMIT 1000
orders_view is defined as follows:
SELECT a.*, b.*, c.*, d.*
FROM orders a
JOIN customers b USING (customerid)
LEFT JOIN exchange c ON c.currencyid = a.currencyid
LEFT JOIN (
SELECT order_items.order_id,
sum(order_items.itemprice * order_items.quantity::numeric) AS totalusd
FROM order_items
GROUP BY order_items.order_id
) d USING (order_id);
Running EXPLAIN ANALYZE on both servers reveals that the culprit is a particular hash join in the query plan that is responsible for the difference, and looking at the buffers, I see that Postgres 13 reads way more data than Postgres 11. Both databases have roughly the same data (one is older than the other, but not by a lot, certainly not nearly enough of a difference for the data to be drastically different). The output of both EXPLAN calls is below:
Postgres 11:
Limit (cost=62302.29..62304.79 rows=1000 width=494) (actual time=2584.169..2585.417 rows=1000 loops=1)
Buffers: shared hit=988575
-> Sort (cost=62302.29..62576.83 rows=109816 width=494) (actual time=2584.167..2584.619 rows=1000 loops=1)
Sort Key: a.orderdate DESC, a.order_id DESC
Sort Method: top-N heapsort Memory: 1108kB
Buffers: shared hit=988575
-> Hash Left Join (cost=2528.32..55183.04 rows=109816 width=494) (actual time=77.678..2423.464 rows=109816 loops=1)
Inner Unique: true
Hash Cond: (a.currencyid = c.currencyid)
Buffers: shared hit=988575
-> Hash Join (cost=2527.07..25955.77 rows=109816 width=496) (actual time=77.469..1104.928 rows=109816 loops=1)
Inner Unique: true
Hash Cond: (a.customerid = b.customerid)
Buffers: shared hit=262074
-> Merge Left Join (cost=0.71..23141.12 rows=109816 width=476) (actual time=0.030..889.032 rows=109816 loops=1)
Inner Unique: true
Merge Cond: (a.order_id = order_items.order_id)
Buffers: shared hit=260903
-> Index Scan using order_id on sales.orders a (cost=0.29..8126.28 rows=109816 width=444) (actual time=0.011..160.707 rows=109816 loops=1)
Buffers: shared hit=79805
-> GroupAggregate (cost=0.42..12696.26 rows=90846 width=36) (actual time=0.017..540.571 rows=109704 loops=1)
Group Key: order_items.order_id
Buffers: shared hit=181098
-> Index Scan using qi_order_id on sales.order_items (cost=0.42..9253.19 rows=230750 width=13) (actual time=0.007..240.223 rows=230750 loops=1)
Buffers: shared hit=181098
-> Hash (cost=1773.38..1773.38 rows=60238 width=24) (actual time=77.405..77.406 rows=60238 loops=1)
Buckets: 65536 Batches: 1 Memory Usage: 3703kB
Buffers: shared hit=1171
-> Seq Scan on sales.customers b (cost=0.00..1773.38 rows=60238 width=24) (actual time=0.008..40.508 rows=60238 loops=1)
Buffers: shared hit=1171
-> Hash (cost=1.11..1.11 rows=11 width=7) (actual time=0.019..0.021 rows=11 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=1
-> Seq Scan on public.exchange c (cost=0.00..1.11 rows=11 width=7) (actual time=0.005..0.012 rows=11 loops=1)
Buffers: shared hit=1
Planning Time: 0.469 ms
Execution Time: 2585.894 ms
Postgres 13:
Limit (cost=61262.22..61264.72 rows=1000 width=494) (actual time=3529.979..3531.221 rows=1000 loops=1)
Buffers: shared hit=2312609
-> Sort (cost=61262.22..61535.21 rows=109199 width=494) (actual time=3529.978..3530.442 rows=1000 loops=1)
Sort Key: a.orderdate DESC, a.order_id DESC
Sort Method: top-N heapsort Memory: 1092kB
Buffers: shared hit=2312609
-> Hash Left Join (cost=2498.13..54182.96 rows=109199 width=494) (actual time=73.761..3363.457 rows=109199 loops=1)
Inner Unique: true
Hash Cond: (a.currencyid = c.currencyid)
Buffers: shared hit=2312609
-> Hash Join (cost=2496.89..25119.89 rows=109199 width=496) (actual time=73.582..1063.430 rows=109199 loops=1)
Inner Unique: true
Hash Cond: (a.customerid = b.customerid)
Buffers: shared hit=259701
-> Merge Left Join (cost=0.84..22337.17 rows=109199 width=476) (actual time=0.033..847.858 rows=109199 loops=1)
Inner Unique: true
Merge Cond: (a.order_id = order_items.order_id)
Buffers: shared hit=258557
-> Index Scan using order_id on sales.orders a (cost=0.42..8109.24 rows=109199 width=444) (actual time=0.007..112.548 rows=109199 loops=1)
Buffers: shared hit=79053
-> GroupAggregate (cost=0.42..12207.54 rows=77662 width=36) (actual time=0.022..520.454 rows=109087 loops=1)
Group Key: order_items.order_id
Buffers: shared hit=179504
-> Index Scan using qi_order_id on sales.order_items (cost=0.42..8946.09 rows=229068 width=13) (actual time=0.013..211.722 rows=229068 loops=1)
Buffers: shared hit=179504
-> Hash (cost=1744.91..1744.91 rows=60091 width=24) (actual time=73.515..73.517 rows=60091 loops=1)
Buckets: 65536 Batches: 1 Memory Usage: 3695kB
Buffers: shared hit=1144
-> Seq Scan on sales.customers b (cost=0.00..1744.91 rows=60091 width=24) (actual time=0.005..36.682 rows=60091 loops=1)
Buffers: shared hit=1144
-> Hash (cost=1.11..1.11 rows=11 width=7) (actual time=0.017..0.019 rows=11 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=1
-> Seq Scan on public.exchange c (cost=0.00..1.11 rows=11 width=7) (actual time=0.003..0.010 rows=11 loops=1)
Buffers: shared hit=1
Planning:
Buffers: shared hit=16
Planning Time: 0.459 ms
Execution Time: 3531.683 ms
We can see that Postgres 11 has only 5.5 GB of shared hits, while Postgres 13 has 16GB of shared hits. I assume this explains the difference in processing time, but leaves me wondering why Postgres 13 is reading so much more data to perform the same query, and what can I do about it?
I tried vacuuming the 13 installation, didn't help at all.
UPDATE: If I put the ORDER BY into the view itself, then suddenly the performance improves drastically on Postgres 13.
New query plan:
Limit (cost=57978.48..58263.48 rows=1000 width=494) (actual time=1394.780..1513.520 rows=1000 loops=1)
Buffers: shared hit=388217, temp read=295 written=296
-> Result (cost=57978.48..88008.21 rows=109199 width=494) (actual time=1394.778..1512.617 rows=1000 loops=1)
Buffers: shared hit=388217, temp read=295 written=296
-> Sort (cost=57978.48..58251.48 rows=109199 width=493) (actual time=1394.549..1395.070 rows=1000 loops=1)
Sort Key: a.orderdate DESC, a.order_id DESC
Sort Method: top-N heapsort Memory: 624kB
Buffers: shared hit=260007, temp read=295 written=296
-> Hash Left Join (cost=23034.29..34629.78 rows=109199 width=493) (actual time=707.751..1293.404 rows=109199 loops=1)
Hash Cond: (a.currencyid = c.currencyid)
Buffers: shared hit=260007, temp read=295 written=296
-> Hash Join (cost=23033.04..32866.46 rows=109199 width=496) (actual time=707.718..1175.399 rows=109199 loops=1)
Hash Cond: (a.customerid = b.customerid)
Buffers: shared hit=260006, temp read=295 written=296
-> Merge Left Join (cost=20536.99..30083.75 rows=109199 width=476) (actual time=633.699..977.524 rows=109199 loops=1)
Merge Cond: (a.order_id = d.order_id)
Buffers: shared hit=258862, temp read=295 written=296
-> Index Scan Backward using order_id on orders a (cost=0.42..8109.24 rows=109199 width=444) (actual time=0.010..98.301 rows=109199 loops=1)
Buffers: shared hit=79358
-> Sort (cost=20536.58..20730.73 rows=77662 width=36) (actual time=633.681..692.837 rows=109087 loops=1)
Sort Key: d.order_id DESC
Sort Method: external merge Disk: 2360kB
Buffers: shared hit=179504, temp read=295 written=296
-> Subquery Scan on d (cost=0.42..12984.16 rows=77662 width=36) (actual time=0.022..560.083 rows=109087 loops=1)
Buffers: shared hit=179504
-> GroupAggregate (cost=0.42..12207.54 rows=77662 width=36) (actual time=0.020..469.442 rows=109087 loops=1)
Group Key: order_items.order_id
Buffers: shared hit=179504
-> Index Scan using qi_order_id on order_items (cost=0.42..8946.09 rows=229068 width=13) (actual time=0.008..203.632 rows=229068 loops=1)
Buffers: shared hit=179504
-> Hash (cost=1744.91..1744.91 rows=60091 width=24) (actual time=73.986..73.988 rows=60091 loops=1)
Buckets: 65536 Batches: 1 Memory Usage: 3695kB
Buffers: shared hit=1144
-> Seq Scan on customers b (cost=0.00..1744.91 rows=60091 width=24) (actual time=0.007..37.447 rows=60091 loops=1)
Buffers: shared hit=1144
-> Hash (cost=1.11..1.11 rows=11 width=7) (actual time=0.023..0.025 rows=11 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=1
-> Seq Scan on exchange c (cost=0.00..1.11 rows=11 width=7) (actual time=0.008..0.015 rows=11 loops=1)
Buffers: shared hit=1
Planning:
Buffers: shared hit=16
Planning Time: 0.444 ms
Execution Time: 1514.405 ms
EXPLAIN (VERBOSE)?