EXPLAIN ANALYZE time calculations
I'd like to get confirmation that I'm correctly understanding the
times given in EXPLAIN ANALYZE. Taking the example given in the Using
Explain section of the docs,
http://www.postgresql.org/docs/current/static/using-explain
EXPLAIN ANALYZE SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 <
100 AND t1.unique2 = t2.unique2;
QUERY PLAN
------------------------------------------------------------------------
----------------------------------------------------------
Nested Loop (cost=2.37..553.11 rows=106 width=488) (actual
time=1.392..12.700 rows=100 loops=1)
-> Bitmap Heap Scan on tenk1 t1 (cost=2.37..232.35 rows=106
width=244) (actual time=0.878..2.367 rows=100 loops=1)
Recheck Cond: (unique1 < 100)
-> Bitmap Index Scan on tenk1_unique1 (cost=0.00..2.37
rows=106 width=0) (actual time=0.546..0.546 rows=100 loops=1)
Index Cond: (unique1 < 100)
-> Index Scan using tenk2_unique2 on tenk2 t2 (cost=0.00..3.01
rows=1 width=244) (actual time=0.067..0.078 rows=1 loops=100)
Index Cond: ("outer".unique2 = t2.unique2)
Total runtime: 14.452 ms
I'm interested in figuring out what percentage of the total runtime
is spent in each node. Here are my calculations.
Nested loop:
actual time: 12.700 ms/loop * 1 loop = 12.700 ms
percent of total runtime: 88%
percent spent in subnodes: 16% + 54% = 70%
percent spent in node: 18%
Bitmap Heap Scan on tenk1:
actual time: 2.367 ms/loop * 1 loop = 2.367 ms
percent of total runtime: 16%
time spent in subnodes: 4%
time spent in node: 12%
Bitmap Heap Scan on tenk1_unique1:
actual time: 0.546 ms/loop * 1 loop = 0.546 ms: 4%
time spent in subnodes: 0%
time spent in node: 4%
Index Scan total time:
actual time: 0.078 ms/loop * 100 loops = 7.80 ms
percent of total runtime: 54%
percent spent in subnodes: 0%
percent spent in node: 54%
executor overhead: 14.452 ms - 12.700 ms = 1.752 ms: 12%
Is this correct?
Michael Glaesemann
grzm seespotcode net
Home |
Main Index |
Thread Index