MIME-Version: 1.0
From: Neto pr <netopr9@gmail.com>
Date: Thu, 7 Sep 2017 20:17:15 -0700
Message-ID: 
 <CA+wPC0OXdN+_8HxhYMWyV9nfD8v+xChvLROiWCiRo=qSve2MjQ@mail.gmail.com>
Subject: Explain Analyze - actual time in loops
To: pgsql-performance@postgresql.org
Content-Type: multipart/alternative; boundary="94eb2c1badfc90f3a10558a5032c"
Precedence: bulk
Sender: pgsql-performance-owner@postgresql.org

--94eb2c1badfc90f3a10558a5032c
Content-Type: text/plain; charset="UTF-8"

Dear,
I'm trying to interpret an Explain Analyze, but I did not understand this:

-> According to the Postgresql documentation at: https://www.postgresql.org/
docs/9.6/static/using-explain.html

" 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

--94eb2c1badfc90f3a10558a5032c
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Dear,<br>I&#39;m trying to interpret an Explain Analyze, b=
ut I did not understand this:<br><br>-&gt; According to the Postgresql docu=
mentation at: <a href=3D"https://www.postgresql.org/docs/9.6/static/using-e=
xplain.html" target=3D"_blank">https://www.postgresql.org/<wbr>docs/9.6/sta=
tic/using-explain.<wbr>html</a><br><br>&quot; the loops value reports the t=
otal number of executions of the node, and the actual time and rows values =
shown are averages per-execution. <br>.... Multiply by the loops value to g=
et the total time actually spent in the node&quot;<br><br>But look at this =
case, in which the total query time was 66 minutes.<br>(Explain Analyze com=
plete and Query at this link: <a href=3D"https://goo.gl/Kp45fu" target=3D"_=
blank">https://goo.gl/Kp45fu</a> )<br><br>What interests me is this section=
:<br><br>############<wbr>#################### ############################=
##<wbr>#####<br>=C2=A0=C2=A0 -&gt; Index Scan using idx_l_partkeylineitem00=
0x on lineitem (cost =3D 0.57..97.65 rows =3D 26 width =3D 36)<br>=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0=C2=A0=C2=A0 (current time =3D 23.615..419.113 rows =3D 30 loops =3D =
26469)<br>=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 Index Cond: (l_partkey =3D part.p_p=
artkey)<br>##############################<wbr>#################### ########=
#########<br>According to the documentation, one should multiply the Actual=
 Time by the number of Loops.<br>That is: 419113 ms -&gt; 419113/1000/60 =
=3D 6.9 minutes * 26469 (loops) =3D 182.6 minutes.<br><br>But how does this=
 stretch take 182.6 minutes, if the entire query ran in 66 minutes?<br><br>=
Of course I&#39;m making a miscalculation, but if anyone can give me a hint=
 as to how I would calculate this time.<br>What I need to know is the time =
spent go through the idx_l_partkeylineitem000x index, remembering that I di=
d an Explain Analyze which is theoretically the actual time spent and not a=
n estimate <br>as happens with the simple Explain .<br><br>thank you and be=
st regards<br>[] &#39;s Neto<br><br></div>

--94eb2c1badfc90f3a10558a5032c--