Postgres SELECT query produces exact same explain analyze results but different execution times in the results

Question

I have a SELECT query which when running produces the exact same plan in terms of indexes being used when doing an explain analyze however the duration of the run is different (2 seconds vs 30 seconds on average).

Why would this be the case?

Query

explain analyze SELECT SUM ((t0.item_cash_staked - t0.item_cash_won)) 
FROM item t0, product t1 
WHERE (((( t0.item_rejection_code_id IS null) 
 AND (t0.item_created_on > '2019-08-01 17:38:33.613+01')) 
 AND (t1.customer_id = 123456)) 
 AND (t1.product_id = t0.product_id));

Explain results

 Aggregate (cost=1984710.64..1984710.65 rows=1 width=32) (actual time=26916.904..26916.905 rows=1 loops=1)
 -> Nested Loop (cost=1.14..1983541.69 rows=233789 width=6) (actual time=4531.244..26765.752 rows=453812 loops=1)
 -> Index Scan using product_idx_01 on product t1 (cost=0.57..172442.67 rows=539262 width=4) (actual time=6.213..4490.454 rows=500133 loops=1)
 Index Cond: (customer_id = 123456)
 -> Index Scan using item_idx_product_id on item t0 (cost=0.57..3.24 rows=12 width=10) (actual time=0.035..0.044 rows=1 loops=500133)
 Index Cond: (product_id = t1.product_id)
 Filter: ((item_rejection_code_id IS NULL) AND (item_created_on > '2019-08-01 17:38:33.613+01'::timestamp with time zone))
 Rows Removed by Filter: 1
 Planning time: 0.409 ms
 Execution time: 26916.999 ms
(10 rows)

Explain Result Faster

 Aggregate (cost=1984710.64..1984710.65 rows=1 width=32) (actual time=1786.816..1786.816 rows=1 loops=1)
 -> Nested Loop (cost=1.14..1983541.69 rows=233789 width=6) (actual time=289.922..1687.398 rows=453812 loops=1)
 -> Index Scan using product_idx_01 on product t1 (cost=0.57..172442.67 rows=539262 width=4) (actual time=0.013..202.082 rows=500133 loops=1)
 Index Cond: (customer_id = 123456)
 -> Index Scan using item_idx_product_id on item t0 (cost=0.57..3.24 rows=12 width=10) (actual time=0.002..0.003 rows=1 loops=500133)
 Index Cond: (product_id = t1.product_id)
 Filter: ((item_rejection_code_id IS NULL) AND (item_created_on > '2019-08-01 17:38:33.613+01'::timestamp with time zone))
 Rows Removed by Filter: 1
 Planning time: 0.275 ms
 Execution time: 1786.866 ms
(10 rows)

I get running a query once will be slower than running it later as it will skip the planning phase, but I have had times where I have run the same query 1 after the other and it still takes approx 25 seconds to run? Why would this be?

Is there anyway of improving the query to make it better performing?

Any help is much appreciated.

• user1822: Most probably caching of data. You can see that when you use explain (analyze, buffers, verbose)
• rdbmsNoob: Thanks, @a-horse-with-no-name
• rdbmsNoob: @a_horse_with_no_name Is there any way of making the query more efficient? Even when removing the SUM aggregation its still 20+ seconds. I have looked at the date to be between old vs current timestamp but still no luck. Or how could I have the caching of data before the query runs? Thanks again
• user1822: Did you try rewriting that to an EXISTS condition instead of the (implicit) join? pastebin.com/sGH0sDUA
• rdbmsNoob: @a_horse_with_no_name gave that a try still no luck :( the item_created_on table dates back to 2016, I have an index on just that column which it uses. Is there any way of caching the data before the query hits. I have just run a analyze both the item table and product table and still get poor results. Why would this be the case?

Answer 1

You can create an index that is specifically designed for the query:

CREATE INDEX ON product (product_id, item_created_on)
 INCLUDE (item_cash_staked, item_cash_won)
 WHERE item_rejection_code_id IS NULL;
VACUUM product;

That should get you and index-only scan.

With old PostgreSQL versions, you can add the columns to the index instead:

CREATE INDEX ON product (product_id, item_created_on, item_cash_staked, item_cash_won)
 WHERE item_rejection_code_id IS NULL;
VACUUM product;

• rdbmsNoob: Thanks @laurenz-albe will this work for Postgres 9.6? Get a syntax error from the INCLUDE part onwards.
• Laurenz Albe: I have added instructions for old PostgreSQL versions.
• rdbmsNoob: Thanks will give it a try :)
• rdbmsNoob: Even after applying the index it still decides to use the item_idx_product_id.
• Laurenz Albe: Did you VACUUM? Does it use the index if you omit the WHERE condition in CREATE INDEX?