help interpreting "explain analyze" output

On 11/26/2013 06:24 PM, David Rysdam wrote:

I'm not really looking for information on how to speed this query
up. I'm just trying to interpret the output enough to tell me which step
is slow:

Seq Scan on mags (cost=0.00..187700750.56 rows=47476 width=4) (actual time=3004851.889..3004851.889 rows=0 loops=1)
Filter: ((signum IS NOT NULL) AND (NOT (SubPlan 1)))
SubPlan 1
-> Materialize (cost=0.00..3713.93 rows=95862 width=4) (actual time=0.011..16.145 rows=48139 loops=94951)
-> Seq Scan on sigs (cost=0.00..2906.62 rows=95862 width=4) (actual time=0.010..674.201 rows=95862 loops=1)
Total runtime: 3004852.005 ms

It looks like the inner seq scan takes 674ms, then the materialize takes
an additional 16ms? Or is that 16ms * 94951? Or 674 * 94951?

And the outer seq scan takes 3004851-3004851 = 0ms?

The actual time shown is not a range. The first number is how long it
took to produce the first row, and the second is how long it took
overall. The Seq Scan on mags took 3004851.889ms to produce the first
(non-existent) row and then it was finished so that's also the overall time.

SubPlan 1 took a total of 674.201ms + 94951 * 16.145ms = 1533658.096ms
which means the Filter line actually took 1471193.793ms to determine
there were no matching rows.

That is, if I understood it correctly myself.

--
Vik

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On Tue, Nov 26, 2013 at 12:24:08PM -0500, David Rysdam wrote:

I'm not really looking for information on how to speed this query
up. I'm just trying to interpret the output enough to tell me which step
is slow:

You might want to read this:
http://www.depesz.com/tag/unexplainable/

Best regards,

depesz