Thread: Query plan with missing timespans

This is a question about how to read "explain analyze".  I've anonymized
column names and table names.

In the output of "explain analyze" below, what was the query doing
between actual time 1.426 and 17.077?

Kind regards,
Andomar


  HashAggregate  (cost=862.02..862.62 rows=48 width=90) (actual
time=17.077..17.077 rows=0 loops=1)
    Group Key: col, col, col
    Buffers: shared hit=6018
    ->  Nested Loop  (cost=1.52..861.18 rows=48 width=90) (actual
time=17.077..17.077 rows=0 loops=1)
          Buffers: shared hit=6018
          ->  Nested Loop  (cost=1.09..26.74 rows=303 width=41) (actual
time=0.033..1.426 rows=384 loops=1)
                Buffers: shared hit=845
                ->  Index Scan using ind on tbl  (cost=0.42..8.44 rows=1
width=8) (actual time=0.010..0.011 rows=1 loops=1)
                      Index Cond: (col = 123)
                      Buffers: shared hit=4
                ->  Index Scan using ind on tbl (cost=0.67..18.28 rows=2
width=49) (actual time=0.020..1.325 rows=384 loops=1)
                      Index Cond: (col = col)
                      Filter: (col = 'value')
                      Rows Removed by Filter: 2720
                      Buffers: shared hit=841
          ->  Index Scan using index on tbl (cost=0.42..2.74 rows=1
width=57) (actual time=0.040..0.040 rows=0 loops=384)
                Index Cond: (col = col)
                Filter: (col = ANY (ARRAY[func('value1'::text),
func('value2'::text)]))
                Rows Removed by Filter: 1
                Buffers: shared hit=5173
  Planning time: 0.383 ms
  Execution time: 17.128 ms


Version: PostgreSQL 9.4.1 on x86_64-unknown-linux-gnu, compiled by gcc
(GCC) 4.4.7 20120313 (Red Hat 4.4.7-11), 64-bit

Andomar <andomar@aule.net> wrote:

> In the output of "explain analyze" below, what was the query
> doing between actual time 1.426 and 17.077?

Looping through 384 index scans of tbl, each taking 0.040 ms.
That's 15.36 ms.  That leaves 0.291 ms unaccounted for, which means
that's about how much time the top level nested loop took to do its
work.

--
Kevin Grittner
EDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

> Looping through 384 index scans of tbl, each taking 0.040 ms.
> That's 15.36 ms.  That leaves 0.291 ms unaccounted for, which means
> that's about how much time the top level nested loop took to do its
> work.
>

Thanks for your reply, interesting!  I'd have thought that this line
actually implied 0 ms:

     actual time=0.040..0.040

But based on your reply this means, it took between 0.040 and 0.040 ms
for each loop?

Is there a way to tell postgres that a function will always return the
same result for the same parameter, within the same transaction?

Kind regards,
Andomar

Yup… read over the Function Volatility Categories page and decide which you need. What you’re describing is STABLE (or slightly stricter than STABLE, since STABLE makes that guarantee only for a single statement within a transaction).

Hello,

At Wed, 22 Apr 2015 21:59:27 +0200, Andomar <andomar@aule.net> wrote in <5537FD9F.3060109@aule.net>
> > Looping through 384 index scans of tbl, each taking 0.040 ms.
> > That's 15.36 ms.  That leaves 0.291 ms unaccounted for, which means
> > that's about how much time the top level nested loop took to do its
> > work.
> >
> 
> Thanks for your reply, interesting!  I'd have thought that this line
> actually implied 0 ms:
> 
>     actual time=0.040..0.040
> 
> But based on your reply this means, it took between 0.040 and 0.040 ms
> for each loop?

You might mistake how to read it (besides the scale:). The index
scan took 40ms as the average through all loops. The number at
the left of '..' is "startup time".

http://www.postgresql.org/docs/9.4/static/sql-explain.html

# Mmm.. this doesn't explain about "startup time".. It's the time
# taken from execution start to returning the first result.

At Wed, 22 Apr 2015 14:18:40 -0600, Jason Petersen <jason@citusdata.com> wrote in
<4FB6E62B-3876-4D5C-9737-52F23D6693B6@citusdata.com>
> > On Apr 22, 2015, at 1:59 PM, Andomar <andomar@aule.net> wrote:
> > 
> > Is there a way to tell postgres that a function will always return the same result for the same parameter, within
thesame transaction?
 
> 
> Yup… read over the Function Volatility Categories
> <http://www.postgresql.org/docs/9.4/static/xfunc-volatility.html>
> page and decide which you need. What you’re describing is
> STABLE (or slightly stricter than STABLE, since STABLE makes
> that guarantee only for a single statement within a
> transaction).

And you will see what volatility category does a function go
under in pg_proc system catalog.

=# select proname, provolatile from pg_proc where oid = 'random'::regproc;
 proname | provolatile 
---------+-------------
 random  | v

random() is a volatile funciton.

http://www.postgresql.org/docs/9.4/static/catalog-pg-proc.html

regards,

-- 
Kyotaro Horiguchi
NTT Open Source Software Center