EXPLAIN ANALYZE time calculations

Поиск
Список
Период
Сортировка
Искать
От
Michael Glaesemann
Тема
EXPLAIN ANALYZE time calculations
Дата
Msg-id
8C0EE80A-42A3-4CC1-850B-2A6B9220B422@seespotcode.net
Список
Дерево обсуждения
EXPLAIN ANALYZE time calculations Michael Glaesemann <grzm@seespotcode.net>
Re: EXPLAIN ANALYZE time calculations Tom Lane <tgl@sss.pgh.pa.us>
Re: EXPLAIN ANALYZE time calculations Michael Glaesemann <grzm@seespotcode.net>
Re: EXPLAIN ANALYZE time calculations Tom Lane <tgl@sss.pgh.pa.us>
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


В списке pgsql-performance по дате отправления
От: Beyers Cronje
Дата:
От: Tom Lane
Дата:
FAQ