Consider the following execution plan:
table, th, td { border: 1px solid black; border-collapse: collapse; } th, td { padding: 5px; text-align: left; } table tr:nth-child(even) { background-color: #eee; } table tr:nth-child(odd) { background-color:#fff; } table th { background-color: black; color: white; }Seq Scan on orders o1 (cost=0.00..18818840.86 rows=3500 width=16) (actual time=0.033..8625.104 rows=99906 loops=1)
Filter: (amount = (SubPlan 1))
Rows Removed by Filter: 600094
Buffers: shared hit=7719778
SubPlan 1
-> Aggregate (cost=26.87..26.87 rows=1 width=32) (actual time=0.012..0.012 rows=1 loops=700000)
Buffers: shared hit=7714631
-> Bitmap Heap Scan on orders o2 (cost=3.45..26.85 rows=8 width=8) (actual time=0.004..0.008 rows=8 loops=700000)
Recheck Cond: (customer_id = o1.customer_id)
Heap Blocks: exact=5597311
Buffers: shared hit=7714631
-> Bitmap Index Scan on orders_customer_id_order_date_idx (cost=0.00..3.45 rows=8 width=0) (actual time=0.003..0.003 rows=8 loops=700000)
Index Cond: (customer_id = o1.customer_id)
Buffers: shared hit=2117320
Planning time: 0.136 ms
Execution time: 8628.724 ms
My expectation would have been that the "Aggregate" step shows the actual time as a product of the number of loops.
The Bitmap Heap Scan takes 0.008ms for each execution, so shouldn't the "actual time" for the "Aggregate" step be 0.008ms * 700000 (= 5600ms)?
The plan was generated using Postgres 10.4 (on Windows 10, but I think that is irrelevant)
Thomas
