Обсуждение: [PERFORM] Explain Analyze - actual time in loops
I'm trying to interpret an Explain Analyze, but I did not understand this:
-> According to the Postgresql documentation at: https://www.postgresql.org/
" the loops value reports the total number of executions of the node, and the actual time and rows values shown are averages per-execution.
.... Multiply by the loops value to get the total time actually spent in the node"
But look at this case, in which the total query time was 66 minutes.
(Explain Analyze complete and Query at this link: https://goo.gl/Kp45fu )
What interests me is this section:
############
-> Index Scan using idx_l_partkeylineitem000x on lineitem (cost = 0.57..97.65 rows = 26 width = 36)
(current time = 23.615..419.113 rows = 30 loops = 26469)
Index Cond: (l_partkey = part.p_partkey)
##############################
According to the documentation, one should multiply the Actual Time by the number of Loops.
That is: 419113 ms -> 419113/1000/60 = 6.9 minutes * 26469 (loops) = 182.6 minutes.
But how does this stretch take 182.6 minutes, if the entire query ran in 66 minutes?
Of course I'm making a miscalculation, but if anyone can give me a hint as to how I would calculate this time.
What I need to know is the time spent go through the idx_l_partkeylineitem000x index, remembering that I did an Explain Analyze which is theoretically the actual time spent and not an estimate
as happens with the simple Explain .
thank you and best regards
[] 's Neto
From: pgsql-performance-owner@postgresql.org [mailto:pgsql-performance-owner@postgresql.org] On Behalf Of Neto pr
Sent: Thursday, September 07, 2017 11:17 PM
To: pgsql-performance@postgresql.org
Subject: [PERFORM] Explain Analyze - actual time in loops
…
################################ ###################################
-> Index Scan using idx_l_partkeylineitem000x on lineitem (cost = 0.57..97.65 rows = 26 width = 36)
(current time = 23.615..419.113 rows = 30 loops = 26469)
Index Cond: (l_partkey = part.p_partkey)
################################################## #################
According to the documentation, one should multiply the Actual Time by the number of Loops.
That is: 419113 ms -> 419113/1000/60 = 6.9 minutes * 26469 (loops) = 182.6 minutes.
But how does this stretch take 182.6 minutes, if the entire query ran in 66 minutes?
……………….
thank you and best regards
[] 's Neto
Neto,
The time you see there is in ms, so the point (‘.’) you see is the digital point.
So, it is 419.113ms or a little less than half a second (0.419sec).
Igor Neyman
You're right, I confused the radix character.
But even so the result is approximate to the previous message, 182 minutes, see below:
419.113 / 1000 = 0.41 seconds * 26469 (loops) = 11093.50 seconds or 184 minutes
After analyzing, I saw that in some places of the plan, it is being used Parallelism. Does this explain why the final value spent (in minutes) to go through the index (184 minutes) is greater than the total query time (66 minutes)?
Neto
From: pgsql-performance-owner@
postgresql.org [mailto:pgsql-performance- owner@postgresql.org] On Behalf Of Neto pr
Sent: Thursday, September 07, 2017 11:17 PM
To: pgsql-performance@postgresql.org
Subject: [PERFORM] Explain Analyze - actual time in loops
…
##############################
## ############################## #####
-> Index Scan using idx_l_partkeylineitem000x on lineitem (cost = 0.57..97.65 rows = 26 width = 36)
(current time = 23.615..419.113 rows = 30 loops = 26469)
Index Cond: (l_partkey = part.p_partkey)
################################################## #################
According to the documentation, one should multiply the Actual Time by the number of Loops.
That is: 419113 ms -> 419113/1000/60 = 6.9 minutes * 26469 (loops) = 182.6 minutes.
But how does this stretch take 182.6 minutes, if the entire query ran in 66 minutes?
……………….
thank you and best regards
[] 's NetoNeto,
The time you see there is in ms, so the point (‘.’) you see is the digital point.
So, it is 419.113ms or a little less than half a second (0.419sec).
Igor Neyman
Neto pr <netopr9@gmail.com> writes:
> After analyzing, I saw that in some places of the plan, it is being used
> Parallelism. Does this explain why the final value spent (in minutes) to go
> through the index (184 minutes) is greater than the total query time (66
> minutes)?
I was just about to ask you about that. If this is under a Gather node,
I believe that the numbers include time expended in all processes.
So if you had three or more workers these results would make sense.
regards, tom lane
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
I need to know the height of a B-tree index (level of the leaf node farthest from the root).
I tried to find this data in PG_INDEXES and PG_CLASS views, but I did not find it.
Does anyone know if Postgresql stores this information, referring to the height of the index tree?
Regards
Neto pr <netopr9@gmail.com> writes:
> After analyzing, I saw that in some places of the plan, it is being used
> Parallelism. Does this explain why the final value spent (in minutes) to go
> through the index (184 minutes) is greater than the total query time (66
> minutes)?
I was just about to ask you about that. If this is under a Gather node,
I believe that the numbers include time expended in all processes.
So if you had three or more workers these results would make sense.
regards, tom lane
Neto pr <netopr9@gmail.com> writes:
> I need to know the height of a B-tree index (level of the leaf node
> farthest from the root).
pageinspect's bt_metap() will give you that --- it's the "level"
field, I believe.
regards, tom lane
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance