Thread: Understanding EXPLAIN ANALYZE output

Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
I'm trying to optimize a large query by looking at
EXPLAIN ANALYZE output.  Here's what I think may be
the most relevant snippet:

    21 ->  Nested Loop  (cost=0.00..108.85 rows=1 width=1196) (actual time=4769.59..4769.59 rows=0 loops=1)
    22       ->  Nested Loop  (cost=0.00..64.78 rows=4 width=131) (actual time=0.41..72.80 rows=1014 loops=1)
    23             ->  Nested Loop  (cost=0.00..40.68 rows=4 width=103) (actual time=0.34..46.51 rows=1014 loops=1)
    24                   ->  Nested Loop  (cost=0.00..32.40 rows=3 width=52) (actual time=0.24..11.07 rows=689 loops=1)
    25                         ->  Index Scan using uc_review_reviewnum on review  (cost=0.00..3.85 rows=1 width=28)
(actualtime=0.12..0.13 rows=1 loops=1) 
    26                               Index Cond: (reviewnum = '1890382'::bpchar)
    27                         ->  Index Scan using idx_customerorder_review_key on customerorder  (cost=0.00..27.90
rows=52width=24) (actual time=0.11..8.07 rows=689 loops=1) 
    28                               Index Cond: ("outer"."key" = customerorder.review_key)
    29                               Filter: (ordertype = 'TEST'::bpchar)
    30                   ->  Index Scan using idx_occurrencehistory_customerorder_key on occurrencehistory
(cost=0.00..3.05rows=2 width=51) (actual time=0.02..0.04 rows=1 loops=689) 
    31                         Index Cond: ("outer"."key" = occurrencehistory.customerorder_key)
    32             ->  Index Scan using pk_user on user  (cost=0.00..5.80 rows=1 width=28) (actual time=0.01..0.01
rows=1loops=1014) 
    33                   Index Cond: ("outer".user_key = user."key")
    34       ->  Index Scan using idx_queryoutcome_occurrencehistory_key on queryoutcome  (cost=0.00..10.28 rows=28
width=1065)(actual time=4.63..4.63 rows=0 loops=1014) 
    35             Index Cond: ("outer"."key" = queryoutcome.occurrencehistory_key)
    36 ->  Index Scan using pk_querydefinition on querydefinition  (cost=0.00..5.99 rows=1 width=58) (never executed)
    37       Index Cond: ("outer".querydefinition_key = querydefinition."key")

If I understand these correctly, line 22's nested loop finished
returning the last row 72.80ms into the query, and then line
21's nested loop returns its 0 rows 4769.59ms into the query.
That would seem to mean 4696.79ms were spent executing the
nested loop on line 21 prior to returning the first row.

If I got that right, how do I figure out what constitutes the
nested loop of line 21?

TIA.

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Alvaro Herrera
Date:
On Wed, Feb 09, 2005 at 11:00:00AM -0700, Ed L. wrote:

>     34       ->  Index Scan using idx_queryoutcome_occurrencehistory_key on queryoutcome  (cost=0.00..10.28 rows=28
width=1065)(actual time=4.63..4.63 rows=0 loops=1014) 

                      ^^^^^^^^^^              ^^^^ 
>     35             Index Cond: ("outer"."key" = queryoutcome.occurrencehistory_key)


> If I understand these correctly, line 22's nested loop finished
> returning the last row 72.80ms into the query, and then line
> 21's nested loop returns its 0 rows 4769.59ms into the query.
> That would seem to mean 4696.79ms were spent executing the
> nested loop on line 21 prior to returning the first row.

4796.0 ms are the time it took for 34's index scan to complete the 1014
loops, I'd think.

--
Alvaro Herrera (<alvherre[@]dcc.uchile.cl>)
"La naturaleza, tan frágil, tan expuesta a la muerte... y tan viva"

Re: Understanding EXPLAIN ANALYZE output

From
Alvaro Herrera
Date:
On Wed, Feb 09, 2005 at 12:54:27PM -0700, Ed L. wrote:
> On Wednesday February 9 2005 12:04, you wrote:

> > 4796.0 ms are the time it took for 34's index scan to complete
> > the 1014 loops, I'd think.
>
> Interesting.  Reindexing the index
>
>     idx_queryoutcome_occurrencehistory_key
>
> sped up the query to sub-second.  This is a 7.3.4 cluster.  I
> wonder if this that 7.3 index bloat bug?

Hard to say, because you didn't provide more info (such as if the index
has the right deletion pattern), but it could be.

--
Alvaro Herrera (<alvherre[@]dcc.uchile.cl>)
"I call it GNU/Linux. Except the GNU/ is silent." (Ben Reiter)

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 12:56, Alvaro Herrera wrote:
> On Wed, Feb 09, 2005 at 12:54:27PM -0700, Ed L. wrote:
> > sped up the query to sub-second.  This is a 7.3.4 cluster.
> > I wonder if this that 7.3 index bloat bug?
>
> Hard to say, because you didn't provide more info (such as if
> the index has the right deletion pattern), but it could be.

What delete pattern would cause the problem?

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Alvaro Herrera
Date:
On Wed, Feb 09, 2005 at 01:11:36PM -0700, Ed L. wrote:
> On Wednesday February 9 2005 12:56, Alvaro Herrera wrote:
> > On Wed, Feb 09, 2005 at 12:54:27PM -0700, Ed L. wrote:
> > > sped up the query to sub-second.  This is a 7.3.4 cluster.
> > > I wonder if this that 7.3 index bloat bug?
> >
> > Hard to say, because you didn't provide more info (such as if
> > the index has the right deletion pattern), but it could be.
>
> What delete pattern would cause the problem?

A key on which you insert on one side and delete on the other.  A table
indexed by date, and you regularly delete the oldest entries, for
example.

--
Alvaro Herrera (<alvherre[@]dcc.uchile.cl>)
"El Maquinismo fue proscrito so pena de cosquilleo hasta la muerte"
(Ijon Tichy en Viajes, Stanislaw Lem)

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
"Ed L." <pgsql@bluepolka.net> writes:
> I'm trying to optimize a large query by looking at
> EXPLAIN ANALYZE output.  Here's what I think may be
> the most relevant snippet:

>     21 ->  Nested Loop  (cost=0.00..108.85 rows=1 width=1196) (actual time=4769.59..4769.59 rows=0 loops=1)
>     22       ->  Nested Loop  (cost=0.00..64.78 rows=4 width=131) (actual time=0.41..72.80 rows=1014 loops=1)
> ...
>     34       ->  Index Scan using idx_queryoutcome_occurrencehistory_key on queryoutcome  (cost=0.00..10.28 rows=28
width=1065)(actual time=4.63..4.63 rows=0 loops=1014) 
>     35             Index Cond: ("outer"."key" = queryoutcome.occurrencehistory_key)

> If I understand these correctly, line 22's nested loop finished
> returning the last row 72.80ms into the query, and then line
> 21's nested loop returns its 0 rows 4769.59ms into the query.

No, you don't understand correctly.  The numbers are not "time into the
query", they are "elapsed time spent within this node and its
children".  The above says that we spent a total of 72.80 msec executing
line 22 and its children, and a total of 4.63*1014 msec executing line
34 (which has no children, so that's all in the indexscan).  That adds
up to 4767.62 msec, so the actual joining at line 21 took only 1.97 msec.
None of this tells you anything about how far "into the query" all this
stuff happened.  It is however clear that line 34 is the bulk of the
time.

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 2:21, Tom Lane wrote:
> "Ed L." <pgsql@bluepolka.net> writes:
> >
> >     21 ->  Nested Loop  (cost=0.00..108.85 rows=1
> > width=1196) (actual time=4769.59..4769.59 rows=0 loops=1) 22
> >       ->  Nested Loop  (cost=0.00..64.78 rows=4 width=131)
> > (actual time=0.41..72.80 rows=1014 loops=1) ...
> >     34       ->  Index Scan using
> > idx_queryoutcome_occurrencehistory_key on queryoutcome
> > (cost=0.00..10.28 rows=28 width=1065) (actual
> > time=4.63..4.63 rows=0 loops=1014) 35             Index
> > Cond: ("outer"."key" = queryoutcome.occurrencehistory_key)
> >
> > If I understand these correctly, line 22's nested loop
> > finished returning the last row 72.80ms into the query, and
> > then line 21's nested loop returns its 0 rows 4769.59ms into
> > the query.
>
> No, you don't understand correctly.  The numbers are not "time
> into the query", they are "elapsed time spent within this node
> and its children".  The above says that we spent a total of
> 72.80 msec executing line 22 and its children, and a total of
> 4.63*1014 msec executing line 34 (which has no children, so
> that's all in the indexscan).  That adds up to 4767.62 msec,
> so the actual joining at line 21 took only 1.97 msec. None of
> this tells you anything about how far "into the query" all
> this stuff happened.  It is however clear that line 34 is the
> bulk of the time.

Very helpful, thanks.  So time spent in that node & its children
= first number of "actual time" * loops?  That seems consistent
with the fact that reindexing the index led to the huge speedup.
If the second number of the "actual time" part means time
elapsed in this node and its children until the last row was
returned, why does it say "actual time=4.63..4.63" instead of
"actual time=4.63..4767.62"?  Would it say that if there had
been 1 row returned instead of none?

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
"Ed L." <pgsql@bluepolka.net> writes:
> If the second number of the "actual time" part means time
> elapsed in this node and its children until the last row was
> returned, why does it say "actual time=4.63..4.63" instead of
> "actual time=4.63..4767.62"?

The reason we do that is to make the "actual" numbers comparable to the
way that the estimated costs are presented.  The estimated costs are for
a single execution of the node, but the inner side of a nestloop join is
re-executed for each row coming from the outer side.  In this case, the
outer side produced 1014 rows so we ran 1014 separate executions of the
inner indexscan.  If we just reported 4767.62 as the total time, it
would look like the estimated indexscan cost of 10.28 was completely out
of whack, which it isn't.  So instead, we report a per-execution cost
and a "loops" number that you have to multiply by if you are thinking
about total time spent.

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Wed, Feb 09, 2005 at 02:37:39PM -0700, Ed L. wrote:
> Very helpful, thanks.  So time spent in that node & its children
> = first number of "actual time" * loops?  That seems consistent
> with the fact that reindexing the index led to the huge speedup.
> If the second number of the "actual time" part means time
> elapsed in this node and its children until the last row was
> returned, why does it say "actual time=4.63..4.63" instead of
> "actual time=4.63..4767.62"?  Would it say that if there had
> been 1 row returned instead of none?

The meaning of the times is (IIRC) derived from the numbers used in the
planning. The first number is "time to first result", the second number
is "time to last result". So if you're doing a "LIMIT 1" query, only
the first number is relevent.

The purpose of the explain output is to determine where the bottlenecks
are and as such each node only counts time spent in it and all its
subnodes. So for example a Sort node has a really high start time
(because all subnodes must complete before sorting can complete) but
the end time is shortly after because it only needs to pump out tuples.

The complication comes because nodes can be executed in their entirety
repeatedly, especially with nested joins, the inner loop is repeatedly
executed with different parameters. I was one of the major contributers
of this feature originally and there was discussion about how to
represent this. I think the rationale is that the figures should not
appear radically different just because a Node is reexecuted a lot, so
you get an extra result "loops" and the numbers look like a single
index scan. If you look at the numbers the planner uses, it follows the
same pattern.

In general, the EXPLAIN ANALYZE output follows the planner output as
close as possible. If you look at the original query posted, it showed
an Index Scan costing 4.63..4.63 which means the index scan is taking
(on average) 4.63ms to return 1 row! If it displayed as 4000 or
something it would be a lot less clear what was going on.

Hope this helps,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 3:13, Martijn van Oosterhout wrote:
>
> In general, the EXPLAIN ANALYZE output follows the planner
> output as close as possible. If you look at the original query
> posted, it showed an Index Scan costing 4.63..4.63 which means
> the index scan is taking (on average) 4.63ms to return 1 row!
> If it displayed as 4000 or something it would be a lot less
> clear what was going on.
>
> Hope this helps,

Both replies help very much, thanks.  Regarding 4.63ms to return
a row, I know I/O speeds vary widely depending on conditions and
hardware, but what would you say is a "red flag" value for the
actual time to retrieve a row.  I see that for most of the other
times in this example, 0.01ms to 0.10ms is not unusual.

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Wed, Feb 09, 2005 at 03:38:32PM -0700, Ed L. wrote:
> On Wednesday February 9 2005 3:13, Martijn van Oosterhout wrote:
> >
> > In general, the EXPLAIN ANALYZE output follows the planner
> > output as close as possible. If you look at the original query
> > posted, it showed an Index Scan costing 4.63..4.63 which means
> > the index scan is taking (on average) 4.63ms to return 1 row!
> > If it displayed as 4000 or something it would be a lot less
> > clear what was going on.
> >
> > Hope this helps,
>
> Both replies help very much, thanks.  Regarding 4.63ms to return
> a row, I know I/O speeds vary widely depending on conditions and
> hardware, but what would you say is a "red flag" value for the
> actual time to retrieve a row.  I see that for most of the other
> times in this example, 0.01ms to 0.10ms is not unusual.

That number 4.63ms is way out. Especially considering this is an
*average* over 1000+ iterations which tells you something it very wrong
with that step. Note, Index Scan can take a long time, it completely
depends on how many rows it returns. Also, if there is an additional
filter on the index (someotherfield = 'x') it may take a while to
return a single value.

But for unique indexes on primary keys (which is what this appears to
be) the times should hopefully be <1ms *average* (caching and load are
imprtant factors).

Hope this helps,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
Thinking about how to make this analysis faster and less labor-
intensive ...

I know of no other way to get the detailed performance data provided
via EXPLAIN ANALYZE without just painfully disassembling a query.
It seems it would be pretty useful w/r/t performance monitoring to
be able to retrieve such performance numbers as those in EXPLAIN
ANALYZE in a rowset via query.  That would seem to enable automated
identification of things like single rows taking 4.63ms to retrieve.
I can think of a number of application queries for which I would
like to do this sort of analysis routinely across a bunch of
database clusters.  I guess one could just parse the explain output
in the meantime but, dreaming a bit here, for example,

   SELECT node_id, op, parent_node_id, index, relation,
          cost_first, cost_last, cost_rows, cost_width,
          actual_first, actual_last, actual_rows, actual_loops,
          index_condition
   FROM pg_explain_analyze('SELECT * FROM foo');

with output similar to

 node_id |     op      | parent_node_id ...  actual_last | actual_rows | actual_loops ...
---------+-------------+----------------...--------------+-------------+--------------...
      21 | Nested Loop |             20 ...        72.80 |        1014 | 1
      22 | Nested Loop |             21 ...        46.51 |        1014 | 1
...
      34 | Index Scan  |             21 ...         4.63 |           0 | 1014
...

Then, as a routine measure, catch those cases like this one,

    SELECT sql, op, index, relation, actual_first
    FROM pg_explain_analyze('SELECT * FROM foo')
    WHERE op = 'Index Scan'
      AND actual_first > 1.0;

Thankfully, I'm sure there are a lot of skilled postgresql'ers
just sitting around right now wishing they had something to do.

Ed


Re: Understanding EXPLAIN ANALYZE output

From
David Fetter
Date:
On Wed, Feb 09, 2005 at 04:34:30PM -0700, Ed L. wrote:
> Thinking about how to make this analysis faster and less labor-
> intensive ...
>
> I know of no other way to get the detailed performance data provided
> via EXPLAIN ANALYZE without just painfully disassembling a query.
> It seems it would be pretty useful w/r/t performance monitoring to
> be able to retrieve such performance numbers as those in EXPLAIN
> ANALYZE in a rowset via query.  That would seem to enable automated
> identification of things like single rows taking 4.63ms to retrieve.
> I can think of a number of application queries for which I would
> like to do this sort of analysis routinely across a bunch of
> database clusters.  I guess one could just parse the explain output
> in the meantime but, dreaming a bit here, for example,
>
>    SELECT node_id, op, parent_node_id, index, relation,
>           cost_first, cost_last, cost_rows, cost_width,
>           actual_first, actual_last, actual_rows, actual_loops,
>           index_condition
>    FROM pg_explain_analyze('SELECT * FROM foo');
>
> with output similar to
>
>  node_id |     op      | parent_node_id ...  actual_last | actual_rows | actual_loops ...
> ---------+-------------+----------------...--------------+-------------+--------------...
>       21 | Nested Loop |             20 ...        72.80 |        1014 | 1
>       22 | Nested Loop |             21 ...        46.51 |        1014 | 1
> ...
>       34 | Index Scan  |             21 ...         4.63 |           0 | 1014
> ...
>
> Then, as a routine measure, catch those cases like this one,
>
>     SELECT sql, op, index, relation, actual_first
>     FROM pg_explain_analyze('SELECT * FROM foo')
>     WHERE op = 'Index Scan'
>       AND actual_first > 1.0;
>
> Thankfully, I'm sure there are a lot of skilled postgresql'ers
> just sitting around right now wishing they had something to do.

Well, I'm a little bored; I've got tomorrow off, and this seems like
it might be doable in the kind of high-level PL/Foo's with which I'm
familiar.  What would the returning rowtype for
pg_explain_analyze(TEXT) be?

Cheers,
D
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Understanding EXPLAIN ANALYZE output

From
"Joshua D. Drake"
Date:
David Fetter wrote:

>On Wed, Feb 09, 2005 at 04:34:30PM -0700, Ed L. wrote:
>
>
>>Thinking about how to make this analysis faster and less labor-
>>intensive ...
>>
>>I know of no other way to get the detailed performance data provided
>>via EXPLAIN ANALYZE without just painfully disassembling a query.
>>It seems it would be pretty useful w/r/t performance monitoring to
>>be able to retrieve such performance numbers as those in EXPLAIN
>>ANALYZE in a rowset via query.  That would seem to enable automated
>>identification of things like single rows taking 4.63ms to retrieve.
>>I can think of a number of application queries for which I would
>>like to do this sort of analysis routinely across a bunch of
>>database clusters.  I guess one could just parse the explain output
>>in the meantime but, dreaming a bit here, for example,
>>
>>   SELECT node_id, op, parent_node_id, index, relation,
>>          cost_first, cost_last, cost_rows, cost_width,
>>          actual_first, actual_last, actual_rows, actual_loops,
>>          index_condition
>>   FROM pg_explain_analyze('SELECT * FROM foo');
>>
>>with output similar to
>>
>> node_id |     op      | parent_node_id ...  actual_last | actual_rows | actual_loops ...
>>---------+-------------+----------------...--------------+-------------+--------------...
>>      21 | Nested Loop |             20 ...        72.80 |        1014 | 1
>>      22 | Nested Loop |             21 ...        46.51 |        1014 | 1
>>...
>>      34 | Index Scan  |             21 ...         4.63 |           0 | 1014
>>...
>>
>>Then, as a routine measure, catch those cases like this one,
>>
>>    SELECT sql, op, index, relation, actual_first
>>    FROM pg_explain_analyze('SELECT * FROM foo')
>>    WHERE op = 'Index Scan'
>>      AND actual_first > 1.0;
>>
>>Thankfully, I'm sure there are a lot of skilled postgresql'ers
>>just sitting around right now wishing they had something to do.
>>
>>
>
>Well, I'm a little bored; I've got tomorrow off, and this seems like
>it might be doable in the kind of high-level PL/Foo's with which I'm
>familiar.  What would the returning rowtype for
>pg_explain_analyze(TEXT) be?
>
>
You could return it as formatted text. if you want to make it simple.

J



>Cheers,
>D
>
>


--
Command Prompt, Inc., home of Mammoth PostgreSQL - S/ODBC and S/JDBC
Postgresql support, programming shared hosting and dedicated hosting.
+1-503-667-4564 - jd@commandprompt.com - http://www.commandprompt.com
PostgreSQL Replicator -- production quality replication for PostgreSQL


Attachment

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 7:31, David Fetter wrote:
> On Wed, Feb 09, 2005 at 04:34:30PM -0700, Ed L. wrote:
> > Thinking about how to make this analysis faster and less
> > labor- intensive ...
> >
> >    SELECT node_id, op, parent_node_id, index, relation,
> >           cost_first, cost_last, cost_rows, cost_width,
> >           actual_first, actual_last, actual_rows,
> > actual_loops, index_condition
> >    FROM pg_explain_analyze('SELECT * FROM foo');
> >
> > Thankfully, I'm sure there are a lot of skilled
> > postgresql'ers just sitting around right now wishing they
> > had something to do.
>
> Well, I'm a little bored; I've got tomorrow off, and this
> seems like it might be doable in the kind of high-level
> PL/Foo's with which I'm familiar.  What would the returning
> rowtype for
> pg_explain_analyze(TEXT) be?

LOL.  If you're serious, I was thinking of something like this:

    node_id    integer not null unique
    op varchar:  "Index Scan"|"Hash Join"|"Seq Scan"|...
    parent_node_id integer:  node_id of parent node
    index varchar:  name of index for scan (oid better?)
    relation varchar:  name of relation for scan (oid better?)
    cost_first float:  first cost number
    cost_last float:  second cost number
    cost_rows bigint
    cost_width integer
    actual_first float:  time to first row
    actual_last float:  time to last row
    actual_rows bigint
    actual_loops bigint
    condition varchar:  what comes after "Index Cond:"|"Hash Cond:"|...
    total_time float:  total query time

How's that?

That might be a start.  This is half-baked and you may be
the new head chef, so feel free.

Ed


Functions with more than 32 parameters

From
"Oisin Glynn"
Date:
Hi,

I am trying to keep database access encapsulated in functions from an insert
and update point of view so as all of the applications writing to the
database are using the same functions/statements.

My problem is I was creating functions to do inserts/updates and now I have
a table with more than 32 columns and the functions seem to only want to
have 32 parameters?

Is there any way around this?

I have used stored procedures in this way with Oracle/SQL server before.Or
is there another strategy I could use?

I am using Windows 2000 Postgres 8.0.1 if it makes a difference

Thanks in advance,
Oisin


Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 8:07, Ed L. wrote:
> >
> > Well, I'm a little bored; I've got tomorrow off, and this
> > seems like it might be doable in the kind of high-level
> > PL/Foo's with which I'm familiar.  What would the returning
> > rowtype for
> > pg_explain_analyze(TEXT) be?
>
> LOL.  If you're serious, I was thinking of something like
> this:
>
>     node_id    integer not null unique
>     op varchar:  "Index Scan"|"Hash Join"|"Seq Scan"|...
>     parent_node_id integer:  node_id of parent node
>     index varchar:  name of index for scan (oid better?)
>     relation varchar:  name of relation for scan (oid better?)
>     cost_first float:  first cost number
>     cost_last float:  second cost number
>     cost_rows bigint
>     cost_width integer
>     actual_first float:  time to first row
>     actual_last float:  time to last row
>     actual_rows bigint
>     actual_loops bigint
>     condition varchar:  what comes after "Index Cond:"|"Hash
> Cond:"|... total_time float:  total query time

You might drive the rowtype by what you (alias I) hope to get out
of it:  1) easy discovery of the slowest parts of the query, 2)
really slow avg row retrieval times (like the 4.63ms/row
discussed earlier in this thread), and I don't know what else.
Part 2 seems straight forward with this scheme, less sure about
part 1.

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Wed, Feb 09, 2005 at 06:31:11PM -0800, David Fetter wrote:
> On Wed, Feb 09, 2005 at 04:34:30PM -0700, Ed L. wrote:
> >
> >     SELECT sql, op, index, relation, actual_first
> >     FROM pg_explain_analyze('SELECT * FROM foo')
> >     WHERE op = 'Index Scan'
> >       AND actual_first > 1.0;
> >
> > Thankfully, I'm sure there are a lot of skilled postgresql'ers
> > just sitting around right now wishing they had something to do.
>
> Well, I'm a little bored; I've got tomorrow off, and this seems like
> it might be doable in the kind of high-level PL/Foo's with which I'm
> familiar.  What would the returning rowtype for
> pg_explain_analyze(TEXT) be?

I started looking at this earlier.  Is it even possible to get
EXPLAIN output via SPI (and thus the PLs' interfaces to SPI)?  Or
would the function have to make a new connection to the database
and issue the EXPLAIN as an ordinary client?  I suppose a proper
implementation would be written in C and would call the internal
functions that generate the output, but I was thinking about how
to do something simple in a higher-level PL.

As for the return type, I was going to look at explain_outNode()
in src/backend/commands/explain.c and get some ideas from there.

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Understanding EXPLAIN ANALYZE output

From
Greg Stark
Date:
"Ed L." <pgsql@bluepolka.net> writes:

> and I don't know what else.

How about being able to search for queries where expected rows and actual rows
are far apart.

--
greg

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
Michael Fuhr <mike@fuhr.org> writes:
> I started looking at this earlier.  Is it even possible to get
> EXPLAIN output via SPI (and thus the PLs' interfaces to SPI)?

Hmm ... my first reaction was "sure", but:

regression=# create or replace function foo() returns setof text as $$
regression$# declare x record;
regression$# begin
regression$# for x in explain select * from tenk1 where unique1 = 42
regression$# loop
regression$#   return next x."QUERY PLAN";
regression$# end loop;
regression$# return;
regression$# end$$ language plpgsql;
CREATE FUNCTION
regression=# select * from foo();
ERROR:  cannot open non-SELECT query as cursor
CONTEXT:  PL/pgSQL function "foo" line 3 at for over select rows

(And no, EXECUTE doesn't help.)  This seems like an oversight.  We
already have some understanding in the backend that certain utility
commands return query results; the SPI code should be letting those
results be scanned as if they were ordinary SELECT results.

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Wed, Feb 09, 2005 at 11:36:22PM -0500, Tom Lane wrote:
> Michael Fuhr <mike@fuhr.org> writes:
> > I started looking at this earlier.  Is it even possible to get
> > EXPLAIN output via SPI (and thus the PLs' interfaces to SPI)?
>
> Hmm ... my first reaction was "sure", but:
[snip]
> ERROR:  cannot open non-SELECT query as cursor

That's what I saw when I started playing with this.  I wasn't sure
if I was overlooking something or if SPI really didn't allow it.

> (And no, EXECUTE doesn't help.)  This seems like an oversight.  We
> already have some understanding in the backend that certain utility
> commands return query results; the SPI code should be letting those
> results be scanned as if they were ordinary SELECT results.

Any suggestions for the meantime?

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Functions with more than 32 parameters

From
Christopher Browne
Date:
Centuries ago, Nostradamus foresaw when me@oisinglynn.com ("Oisin Glynn") would write:
> I am trying to keep database access encapsulated in functions from an
> insert and update point of view so as all of the applications writing
> to the database are using the same functions/statements.
>
> My problem is I was creating functions to do inserts/updates and now I
> have a table with more than 32 columns and the functions seem to only
> want to have 32 parameters?
>
> Is there any way around this?
>
> I have used stored procedures in this way with Oracle/SQL server
> before.  Or is there another strategy I could use?
>
> I am using Windows 2000 Postgres 8.0.1 if it makes a difference

Certainly you can change this.

Edit the following file in your source tree:

cbbrowne@wolfe:/brownes/wolfe/compiles/pgsql> vi src/include/pg_config_manual.h

/*
 * Maximum number of columns in an index and maximum number of
 * arguments to a function. They must be the same value.
 *
 * The minimum value is 8 (index creation uses 8-argument functions).
 * There is no specific upper limit, although large values will waste
 * system-table space and processing time.
 *
 * Changing these requires an initdb.
 */
#define INDEX_MAX_KEYS          32
#define FUNC_MAX_ARGS           INDEX_MAX_KEYS

You will have to recompile PostgreSQL and create a fresh database
instance using initdb with the new maxima for these configuration
values.

Fortunately, the ability to recompile as needed is one of the most
important points of this "open source" stuff...
--
"cbbrowne","@","gmail.com"
http://linuxdatabases.info/~cbbrowne/spreadsheets.html
They are  called  computers  simply  because computation  is  the only
significant job that has so far been given to them.  -- Louis Ridenour

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Wednesday February 9 2005 10:10, Michael Fuhr wrote:
>
> > (And no, EXECUTE doesn't help.)  This seems like an
> > oversight.  We already have some understanding in the
> > backend that certain utility commands return query results;
> > the SPI code should be letting those results be scanned as
> > if they were ordinary SELECT results.
>
> Any suggestions for the meantime?

Well, this would be a bit unsightly and not exactly elegant, but
I'd think you could do this via DBI from within plperl or maybe
plperlu...

Ed


Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Thu, Feb 10, 2005 at 08:04:52AM -0700, Ed L. wrote:
> On Wednesday February 9 2005 10:10, Michael Fuhr wrote:
> >
> > Any suggestions for the meantime?
>
> Well, this would be a bit unsightly and not exactly elegant, but
> I'd think you could do this via DBI from within plperl or maybe
> plperlu...

Yeah, that's exactly what I was doing when I started playing with
this yesterday.  dblink works too.

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Functions with more than 32 parameters

From
David Fetter
Date:
On Wed, Feb 09, 2005 at 10:11:19PM -0500, Oisin Glynn wrote:
> Hi,
>
> I am trying to keep database access encapsulated in functions from an
> insert and update point of view so as all of the applications writing to
> the database are using the same functions/statements.
>
> My problem is I was creating functions to do inserts/updates and now I have
> a table with more than 32 columns and the functions seem to only want to
> have 32 parameters?
>
> Is there any way around this?

Short of recompiling as others have suggested, you could put large #
of params into an array and have the function unwind that.

Cheers,
D
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
Michael Fuhr <mike@fuhr.org> writes:
> On Wed, Feb 09, 2005 at 11:36:22PM -0500, Tom Lane wrote:
>> (And no, EXECUTE doesn't help.)  This seems like an oversight.  We
>> already have some understanding in the backend that certain utility
>> commands return query results; the SPI code should be letting those
>> results be scanned as if they were ordinary SELECT results.

> Any suggestions for the meantime?

Update to CVS tip ;-)

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
David Fetter
Date:
On Thu, Feb 10, 2005 at 03:38:05PM -0500, Tom Lane wrote:
> Michael Fuhr <mike@fuhr.org> writes:
> > On Wed, Feb 09, 2005 at 11:36:22PM -0500, Tom Lane wrote:
> >> (And no, EXECUTE doesn't help.)  This seems like an oversight.
> >> We already have some understanding in the backend that certain
> >> utility commands return query results; the SPI code should be
> >> letting those results be scanned as if they were ordinary SELECT
> >> results.
>
> > Any suggestions for the meantime?
>
> Update to CVS tip ;-)

I'd be delighted to, but I'm not sure how to see to it that EXPLAIN
gets the CMD_SELECT flag.  What all files need to change to effect
this?  Or have I drastically misunderstood what's involved?

Cheers,
D
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Functions with more than 32 parameters

From
Michael Fuhr
Date:
On Thu, Feb 10, 2005 at 10:07:50AM -0800, David Fetter wrote:
>
> Short of recompiling as others have suggested, you could put large #
> of params into an array and have the function unwind that.

In 8.0 or later, you could also use a function that takes a single
parameter of a composite type and use a row constructor when you
call it.

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
David Fetter <david@fetter.org> writes:
> I'd be delighted to, but I'm not sure how to see to it that EXPLAIN
> gets the CMD_SELECT flag.  What all files need to change to effect
> this?  Or have I drastically misunderstood what's involved?

It doesn't.  See
http://archives.postgresql.org/pgsql-committers/2005-02/msg00073.php

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
Harald Fuchs
Date:
In article <2300.1108067885@sss.pgh.pa.us>,
Tom Lane <tgl@sss.pgh.pa.us> writes:

> Michael Fuhr <mike@fuhr.org> writes:
>> On Wed, Feb 09, 2005 at 11:36:22PM -0500, Tom Lane wrote:
>>> (And no, EXECUTE doesn't help.)  This seems like an oversight.  We
>>> already have some understanding in the backend that certain utility
>>> commands return query results; the SPI code should be letting those
>>> results be scanned as if they were ordinary SELECT results.

>> Any suggestions for the meantime?

> Update to CVS tip ;-)

The faint-hearted could use a separate connection instead; something
like that:

  CREATE TYPE expl_t AS (
    id INT,
    type TEXT,
    relation TEXT,
    cost1 FLOAT,
    cost2 FLOAT,
    rows INT,
    width INT,
    atime1 FLOAT,
    atime2 FLOAT,
    arows INT,
    loops INT
  );

  CREATE OR REPLACE FUNCTION pg_explain_analyze(TEXT) RETURNS SETOF expl_t AS $$
    my $sql = $_[0];
    my $rv = spi_exec_query('SELECT current_database()');
    my $db = $rv->{rows}[0]->{current_database};
    # Grab EXPLAIN output
    use strict;
    use warnings;
    use DBI;
    my $dbh = DBI->connect("DBI:Pg:dbname=$db", "", "", {
      AutoCommit => 0,
      PrintError => 0,
      RaiseError => 1,
    });
    my $sth = $dbh->prepare("EXPLAIN ANALYZE $sql");
    $sth->execute();
    my @res = ();
    my @nm = qw(type relation cost1 cost2 rows width atime1 atime2 arows loops);
    my $cnt = 0;
    while (my $res = $sth->fetchrow_arrayref) {
      my @a = $res->[0] =~ m{
        ^(?:\s+->\s\s)?               # Prefix
        (\S+(?:\s\S+)?)               # Operation
        (?:\son\s(\S+)(?:\s\S+)?)?    # on table [alias]
        \s\s                          # Estimations:
        \(cost=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\swidth=(\d+)\)
        \s                            # Actual values:
        \(actual\stime=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\sloops=(\d+)\)$
      }x or next;
      my %elt = (id => ++$cnt);
      $elt{$nm[$_]} = $a[$_] for (0..$#nm);
      push @res, \%elt;
    }
    $dbh->disconnect;
    return \@res;
  $$ LANGUAGE "plperlu";

This happily ignores index conditions etc for now, but it might be a start.

But I think it should be the other way round:  EXPLAIN ANALYZE should
return its output in table form, and there should be a function to
convert that table into what EXPLAIN ANALYZE outputs now.

Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Thu, Feb 10, 2005 at 03:38:05PM -0500, Tom Lane wrote:
> Michael Fuhr <mike@fuhr.org> writes:
>
> > Any suggestions for the meantime?
>
> Update to CVS tip ;-)

Done.  Below is a simple proof of concept for an explain() function
in PL/pgSQL.  It's not necessarily correct -- it just shows what
could be done.

CREATE TYPE explain_in AS (
    exp  text
);

CREATE TYPE explain_out AS (
    pname         text,
    startup_cost  numeric(12,2),
    total_cost    numeric(12,2),
    plan_rows     integer,
    plan_width    integer
);

CREATE FUNCTION explain(query text) RETURNS SETOF explain_out AS $$
DECLARE
    row  explain_in;
    ret  explain_out;
BEGIN
    FOR row IN EXECUTE 'EXPLAIN ' || query LOOP
    ret.pname        := substring(row.exp FROM '([^\\(]+) \\(');
    ret.startup_cost := substring(row.exp FROM 'cost=(\\d+\\.\\d+)');
    ret.total_cost   := substring(row.exp FROM '\\.\\.(\\d+\\.\\d+) rows');
    ret.plan_rows    := substring(row.exp FROM ' rows=([[:digit:]]+)');
    ret.plan_width   := substring(row.exp FROM ' width=([[:digit:]]+)');

    IF ret.plan_rows IS NOT NULL THEN
        RETURN NEXT ret;
    END IF;
    END LOOP;

    RETURN;
END;
$$ LANGUAGE plpgsql VOLATILE STRICT;

SELECT * FROM explain('SELECT count(*) FROM pg_class');
            pname            | startup_cost | total_cost | plan_rows | plan_width
-----------------------------+--------------+------------+-----------+------------
 Aggregate                   |        26.69 |      26.69 |         1 |          0
   ->  Seq Scan on pg_class  |         0.00 |      24.95 |       695 |          0
(2 rows)

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Thu, Feb 10, 2005 at 03:48:48PM -0700, Michael Fuhr wrote:
>
> Below is a simple proof of concept for an explain() function
> in PL/pgSQL.

Do PL/Perl and the other PLs require any changes to make this work?
I tried $rv = spi_exec_query("EXPLAIN $query") but $rv contained
only the following:

$rv->{processed} = 0
$rv->{status} = SPI_OK_UTILITY

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Thu, Feb 10, 2005 at 11:38:47PM +0100, Harald Fuchs wrote:
> But I think it should be the other way round:  EXPLAIN ANALYZE should
> return its output in table form, and there should be a function to
> convert that table into what EXPLAIN ANALYZE outputs now.

I've been wondering about that. A while ago the change was made from
outputting a NOTICE with the EXPLAIN output to returning a resultset.
If you could agree on what columns to return it might not be so hard
for the EXPLAIN to return full tuples...

Backward compatability is a problem though...
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
Michael Fuhr
Date:
On Fri, Feb 11, 2005 at 12:06:45AM +0100, Martijn van Oosterhout wrote:
> On Thu, Feb 10, 2005 at 11:38:47PM +0100, Harald Fuchs wrote:
> > But I think it should be the other way round:  EXPLAIN ANALYZE should
> > return its output in table form, and there should be a function to
> > convert that table into what EXPLAIN ANALYZE outputs now.
>
> I've been wondering about that. A while ago the change was made from
> outputting a NOTICE with the EXPLAIN output to returning a resultset.
> If you could agree on what columns to return it might not be so hard
> for the EXPLAIN to return full tuples...

That does seem cleaner than parsing the EXPLAIN output as we're
playing with right now.  I've been assuming that these experiments
are merely proof of concept and prototypes for how we'd like it to
work.

> Backward compatability is a problem though...

What about making both ways work?  EXPLAIN would format the output
the way it currently looks, and SELECT * FROM explain(...) would
return a resultset.

--
Michael Fuhr
http://www.fuhr.org/~mfuhr/

Re: Understanding EXPLAIN ANALYZE output

From
David Fetter
Date:
On Thu, Feb 10, 2005 at 05:19:41PM -0500, Tom Lane wrote:
> David Fetter <david@fetter.org> writes:
> > I'd be delighted to, but I'm not sure how to see to it that EXPLAIN
> > gets the CMD_SELECT flag.  What all files need to change to effect
> > this?  Or have I drastically misunderstood what's involved?
>
> It doesn't.  See
> http://archives.postgresql.org/pgsql-committers/2005-02/msg00073.php

Yay!!

Thanks a big bunch, Tom :)

Cheers,
D
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
Martijn van Oosterhout <kleptog@svana.org> writes:
> I've been wondering about that. A while ago the change was made from
> outputting a NOTICE with the EXPLAIN output to returning a resultset.
> If you could agree on what columns to return it might not be so hard
> for the EXPLAIN to return full tuples...

The major stumbling block to that is that a table is inherently
unordered, so you'd have to devise a labeling scheme to allow the
node-tree structure to be represented properly.  And without WITH or
CONNECT BY, it'd be a bit of a PITA for an application to decipher the
labeling scheme again ...

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
"Ed L."
Date:
On Thursday February 10 2005 5:01, David Fetter wrote:
> On Thu, Feb 10, 2005 at 05:19:41PM -0500, Tom Lane wrote:
> > David Fetter <david@fetter.org> writes:
> > > I'd be delighted to, but I'm not sure how to see to it
> > > that EXPLAIN gets the CMD_SELECT flag.  What all files
> > > need to change to effect this?  Or have I drastically
> > > misunderstood what's involved?
> >
> > It doesn't.  See
> > http://archives.postgresql.org/pgsql-committers/2005-02/msg0
> >0073.php
>
> Yay!!
>
> Thanks a big bunch, Tom :)

Doodz, u r so phat!  We'd still be working out who
should be invited to the first requirements analysis
meeting if this were at company X...

This is close but my regexes are not quite right...

CREATE TYPE pg_explain_analyze_in AS (
    exp  text
);

CREATE TYPE pg_explain_analyze_out AS (
        node_id integer,
        node varchar,
        parent_node_id integer,
        level integer,
        index varchar,
        relation varchar,
        plan_startup_cost float,
        plan_total_cost float,
        plan_rows bigint,
        plan_width integer,
        act_startup_cost float,
        act_total_cost float,
        act_rows bigint,
        act_loops bigint,
        condition varchar,
        filter varchar,
        total_time float,
        raw_out varchar
);

CREATE OR REPLACE FUNCTION pg_explain_analyze(query text) RETURNS SETOF pg_explain_analyze_out AS $$
DECLARE
    row  pg_explain_analyze_in;
    ret  pg_explain_analyze_out;
    i    integer;
    indent integer;
BEGIN
    i = 0;
    FOR row IN EXECUTE 'EXPLAIN ANALYZE ' || query LOOP
      ret.node_id           := i;
      row.exp               := replace(row.exp, '->  ', '');
      ret.node              := substring(row.exp FROM '[->  ]?(\\S[^\\(:]+) \\(');
      ret.parent_node_id    := -1;
      ret.level             := length(substring(row.exp FROM '^(\\s*)\\S'));
      ret.index             := substring(row.exp FROM 'Index Scan using (\\S+) on \\S+');
      ret.relation          := substring(row.exp FROM 'Scan using \\S+ on (\\S+)');
      ret.plan_startup_cost := substring(row.exp FROM 'cost=(\\d+\\.\\d+)');
      ret.plan_total_cost   := substring(row.exp FROM 'cost=\\d+\\.\\d+\\.\\.(\\d+\\.\\d+) rows');
      ret.plan_rows         := substring(row.exp FROM ' rows=([[:digit:]]+) width');
      ret.plan_width        := substring(row.exp FROM ' width=([[:digit:]]+)');
      ret.act_startup_cost  := substring(row.exp FROM ' width=([[:digit:]]+)');
      ret.act_total_cost    := substring(row.exp FROM ' width=([[:digit:]]+)');
      ret.act_startup_cost  := substring(row.exp FROM 'time=(\\d+\\.\\d+)');
      ret.act_total_cost    := substring(row.exp FROM 'time=\\d+\\.\\d+\\.\\.(\\d+\\.\\d+) rows');
      ret.act_rows          := substring(row.exp FROM ' rows=([[:digit:]]+) loops');
      ret.act_loops         := substring(row.exp FROM ' rows=[[:digit:]]+ loops=([[:digit:]]+)\\)');
      ret.condition         := substring(row.exp FROM 'Cond: \\((\\.+)\\)');
      ret.filter            := substring(row.exp FROM 'Filter: \\((\\.*)\\)');
      ret.total_time        := substring(row.exp FROM 'Total runtime: (\\d+\\.\\d+) ms');
      ret.raw_out           := row.exp;

      IF substring(row.exp FROM '\\S') IS NOT NULL THEN
          RETURN NEXT ret;
      END IF;
      i := i + 1;
    END LOOP;

    RETURN;
END;
$$ LANGUAGE plpgsql VOLATILE STRICT;


% psql -c "explain analyze select * from foobarbaz_view where id < 3;"
                                                        QUERY PLAN
  

--------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..15.13 rows=2 width=12) (actual time=0.060..0.090 rows=2 loops=1)
   ->  Nested Loop  (cost=0.00..9.08 rows=2 width=12) (actual time=0.043..0.059 rows=2 loops=1)
         ->  Index Scan using baz_pkey on baz  (cost=0.00..3.03 rows=2 width=8) (actual time=0.017..0.021 rows=2
loops=1)
               Index Cond: (id < 3)
         ->  Index Scan using bar_pkey on bar  (cost=0.00..3.01 rows=1 width=8) (actual time=0.012..0.014 rows=1
loops=2)
               Index Cond: ("outer".bar_id = bar.id)
   ->  Index Scan using foo_pkey on foo  (cost=0.00..3.01 rows=1 width=4) (actual time=0.010..0.011 rows=1 loops=2)
         Index Cond: ("outer".foo_id = foo.id)
 Total runtime: 0.226 ms
(9 rows)

% psql -c "SELECT case when node notnull then node||'(cost='||plan_startup_cost||'..'||plan_total_cost||'
rows='||plan_rows||'width='||plan_width||') (actual time='||act_startup_cost||'..'||act_total_cost||'
rows='||act_rows||'loops='||act_loops||' per row='||case when act_rows > 0 then to_char(act_total_cost/act_rows,
'9.999')else '0.00' end||')' else 'Total runtime: '||total_time||' ms' end FROM pg_explain_analyze('select * from
foobarbaz_viewwhere id < 3');" 
                                                          case
 

-------------------------------------------------------------------------------------------------------------------------
 Nested Loop (cost=0..15.13 rows=2 width=12) (actual time=0.058..0.088 rows=2 loops=1 per row=  .044)
 Nested Loop (cost=0..9.08 rows=2 width=12) (actual time=0.04..0.056 rows=2 loops=1 per row=  .028)
 Index Scan using baz_pkey on baz (cost=0..3.03 rows=2 width=8) (actual time=0.016..0.02 rows=2 loops=1 per row=  .010)

 Index Scan using bar_pkey on bar (cost=0..3.01 rows=1 width=8) (actual time=0.011..0.012 rows=1 loops=2 per row=
.012)

 Index Scan using foo_pkey on foo (cost=0..3.01 rows=1 width=4) (actual time=0.01..0.011 rows=1 loops=2 per row=  .011)

 Total runtime: 0.2 ms
(9 rows)



Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
Michael Fuhr <mike@fuhr.org> writes:
> Do PL/Perl and the other PLs require any changes to make this work?
> I tried $rv = spi_exec_query("EXPLAIN $query") but $rv contained
> only the following:

> $rv->{processed} = 0
> $rv->{status} = SPI_OK_UTILITY

Looking around, it seems that the PLs (and a lot of contrib modules) are
using SPI_execute rather than the SPI cursor features --- which is what
I fixed.  It looks from the code like SPI_execute does the right things
in terms of returning a tuple table, but it returns completion code
SPI_OK_UTILITY; and these callers only expect there to be result rows
when SPI_execute returns SPI_OK_SELECT.

Seems we have three possibilities to fix this:

1. Alter SPI_execute to say SPI_OK_SELECT after executing a utility
statement that returns tuples.

2. Leave SPI_execute alone and fix the callers.

3. Invent a new result code (SPI_OK_UTILITY_TUPLES maybe?) to return
in this case ... which means changing both SPI_execute *and* the
callers.  It would probably even propagate up to user code, since plperl
for one exposes the set of SPI result codes...

None of these seem especially attractive :-(.  Any thoughts?

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
David Fetter
Date:
On Thu, Feb 10, 2005 at 08:11:42PM -0500, Tom Lane wrote:
> Michael Fuhr <mike@fuhr.org> writes:
> > Do PL/Perl and the other PLs require any changes to make this work?
> > I tried $rv = spi_exec_query("EXPLAIN $query") but $rv contained
> > only the following:
>
> > $rv->{processed} = 0
> > $rv->{status} = SPI_OK_UTILITY
>
> Looking around, it seems that the PLs (and a lot of contrib modules) are
> using SPI_execute rather than the SPI cursor features --- which is what
> I fixed.  It looks from the code like SPI_execute does the right things
> in terms of returning a tuple table, but it returns completion code
> SPI_OK_UTILITY; and these callers only expect there to be result rows
> when SPI_execute returns SPI_OK_SELECT.
>
> Seems we have three possibilities to fix this:
>
> 1. Alter SPI_execute to say SPI_OK_SELECT after executing a utility
> statement that returns tuples.

This doesn't sound good.

> 2. Leave SPI_execute alone and fix the callers.

By "fix the callers," do you mean "outfit them with SPI cursor
features," or something else?  Outfitting with SPI cursor features
would solve some problems I've been having in re: materializing entire
relations into memory, and I suspect that others will run into them,
too.  How big a job would this be?

> 3. Invent a new result code (SPI_OK_UTILITY_TUPLES maybe?) to return
> in this case ... which means changing both SPI_execute *and* the
> callers.  It would probably even propagate up to user code, since
> plperl for one exposes the set of SPI result codes...

This sounds *really* bad.

Cheers,
D
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
David Fetter <david@fetter.org> writes:
> On Thu, Feb 10, 2005 at 08:11:42PM -0500, Tom Lane wrote:
>> Seems we have three possibilities to fix this:
>>
>> 1. Alter SPI_execute to say SPI_OK_SELECT after executing a utility
>> statement that returns tuples.

> This doesn't sound good.

It does seem like it's obscuring a distinction that some callers might
care about.  On the other hand, it would be a localized solution.

>> 2. Leave SPI_execute alone and fix the callers.

> By "fix the callers," do you mean "outfit them with SPI cursor
> features," or something else?

I meant teach them to accept rows when the result is either OK_SELECT
or OK_UTILITY.  I'm not volunteering to cursor-ify all the PLs ;-)
... not that I have anything against it, it's just not high on my own
to-do list.

> How big a job would this be?

Big, I would think; in most cases it would mean defining a new API to
expose to users of the PL, no?

>> 3. Invent a new result code (SPI_OK_UTILITY_TUPLES maybe?) to return
>> in this case ... which means changing both SPI_execute *and* the
>> callers.  It would probably even propagate up to user code, since
>> plperl for one exposes the set of SPI result codes...

> This sounds *really* bad.

It's the only one that really preserves a clean distinction between the
various cases.

After thinking it over, I realize that #2 would affect user code too,
since the knowledge that SPI_OK_UTILITY might imply rows are available
would propagate right up to anything that could see the result code.
(Exposing that code to plperl users might not have been such a hot idea,
but I suppose it's done now.)  So I now do not like #2: it saves nothing
in terms of the amount of code we have to touch, and it loses the
distinction between utility statements that can return tuples and those
that can't.  The realistic alternatives are #1 (small code change, but
a bit ugly) and #3 (lots of code change, but preserves a distinction
that some people may care about).

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
David Fetter
Date:
On Thu, Feb 10, 2005 at 09:51:18PM -0500, Tom Lane wrote:
> David Fetter <david@fetter.org> writes:
> > On Thu, Feb 10, 2005 at 08:11:42PM -0500, Tom Lane wrote:
> >> Seems we have three possibilities to fix this:
> >>
> >> 1. Alter SPI_execute to say SPI_OK_SELECT after executing a utility
> >> statement that returns tuples.
>
> > This doesn't sound good.
>
> It does seem like it's obscuring a distinction that some callers might
> care about.  On the other hand, it would be a localized solution.
>
> >> 2. Leave SPI_execute alone and fix the callers.
>
> > By "fix the callers," do you mean "outfit them with SPI cursor
> > features," or something else?
>
> I meant teach them to accept rows when the result is either OK_SELECT
> or OK_UTILITY.

At least in pl/perl, this appears to be a one-line change.

> I'm not volunteering to cursor-ify all the PLs ;-) ... not that I
> have anything against it, it's just not high on my own to-do list.

Any idea what size such a project might be?

> > How big a job would this be?
>
> Big, I would think; in most cases it would mean defining a new API
> to expose to users of the PL, no?

I suppose it would.  spi_exec_query() appears to be a thin wrapper
around an SPI utility of a similar name.  The needed functions appear
to be the rest of the interface functions, possibly with the exception
of SPI_saveplan().

> >> 3. Invent a new result code (SPI_OK_UTILITY_TUPLES maybe?) to
> >> return in this case ... which means changing both SPI_execute
> >> *and* the callers.  It would probably even propagate up to user
> >> code, since plperl for one exposes the set of SPI result codes...
>
> > This sounds *really* bad.
>
> It's the only one that really preserves a clean distinction between
> the various cases.
>
> After thinking it over, I realize that #2 would affect user code
> too, since the knowledge that SPI_OK_UTILITY might imply rows are
> available would propagate right up to anything that could see the
> result code.  (Exposing that code to plperl users might not have
> been such a hot idea, but I suppose it's done now.)  So I now do not
> like #2: it saves nothing in terms of the amount of code we have to
> touch, and it loses the distinction between utility statements that
> can return tuples and those that can't.

Where is this distinction in SPI?

> The realistic alternatives are #1 (small code change, but a bit
> ugly) and #3 (lots of code change, but preserves a distinction that
> some people may care about).

I think #2 in its weaker form[1] still has some potential.

Cheers,
D

[1] Not cursor-ifying.  Although cursor-ifying the PL's would be a
Good Thing(TM))
--
David Fetter david@fetter.org http://fetter.org/
phone: +1 510 893 6100   mobile: +1 415 235 3778

Remember to vote!

Re: Functions with more than 32 parameters

From
Christopher Browne
Date:
Certainly you can change this.

Edit the following file in your source tree:

cbbrowne@wolfe:/brownes/wolfe/compiles/pgsql> vi src/include/pg_config_manual.h

/*
 * Maximum number of columns in an index and maximum number of
 * arguments to a function. They must be the same value.
 *
 * The minimum value is 8 (index creation uses 8-argument functions).
 * There is no specific upper limit, although large values will waste
 * system-table space and processing time.
 *
 * Changing these requires an initdb.
 */
#define INDEX_MAX_KEYS          32
#define FUNC_MAX_ARGS           INDEX_MAX_KEYS

You will have to recompile PostgreSQL and create a fresh database
instance using initdb with the new maxima for these configuration
values.

Fortunately, the ability to recompile as needed is kind of the whole
point of this "open source" stuff...
--
"cbbrowne","@","gmail.com"
http://linuxdatabases.info/~cbbrowne/spreadsheets.html
They are  called  computers  simply  because computation  is  the only
significant job that has so far been given to them.  -- Louis Ridenour

Re: Understanding EXPLAIN ANALYZE output

From
Tom Lane
Date:
David Fetter <david@fetter.org> writes:
> On Thu, Feb 10, 2005 at 09:51:18PM -0500, Tom Lane wrote:
>> ... it loses the distinction between utility statements that
>> can return tuples and those that can't.

> Where is this distinction in SPI?

Well, the point is that there are potentially three types of statements
involved:

    1. SELECTs
    2. Utility statements that can return tuples (EXPLAIN, SHOW, etc)
    3. Utility statements that can't return tuples (ALTER, etc)

The current SPI API is only designed to account for 1 and 3, failing to
consider 2 in any meaningful fashion.  (In particular, there's really no
way to tell the difference between a 2-that-happened-to-return-zero-
rows-this-time and a 3.)  This of course is because category 2 did not
exist at the time that SPI was designed.

The $64 question is whether anyone *needs* to make these distinctions.
If we arrange to return SPI_OK_SELECT for category 2, then callers won't
be able to tell the difference between categories 1 and 2, but on the
other hand a zero-row result set will still be properly classified as
a SELECT-like operation.  If we leave the API as it stands today then a
zero-row result set looks like a category 3, which arguably is a worse
categorization.

I'm not sure that any of the statements in question actually can return
zero-row result sets today, but I think it would be bad to make these
decisions on the basis of assuming that the case will never arise.

            regards, tom lane

Re: Understanding EXPLAIN ANALYZE output

From
Greg Stark
Date:
Tom Lane <tgl@sss.pgh.pa.us> writes:

> Martijn van Oosterhout <kleptog@svana.org> writes:
> > I've been wondering about that. A while ago the change was made from
> > outputting a NOTICE with the EXPLAIN output to returning a resultset.
> > If you could agree on what columns to return it might not be so hard
> > for the EXPLAIN to return full tuples...
>
> The major stumbling block to that is that a table is inherently
> unordered, so you'd have to devise a labeling scheme to allow the
> node-tree structure to be represented properly.  And without WITH or
> CONNECT BY, it'd be a bit of a PITA for an application to decipher the
> labeling scheme again ...

Only if we chose to represent the tree structure in a way that required it
(like Oracle). There are other ways to represent tree structures.

What if we used integer arrays in an ltree-like way:

[0]      Nested Loop  (cost=0.00..1369.49 rows=8230 width=945)
[0,0]      Join Filter: ("outer".store_location_ids *= "inner".store_location_id)
[0,1]      ->  Index Scan using idx_cache_ads on cache_ads  (cost=0.00..3.17 rows=1 width=219)
[0,1,0]          Index Cond: ((region_id = 12159) AND (ad_id = 132094))
[0,2]      ->  Seq Scan on store_location  (cost=0.00..1160.59 rows=16459 width=726)

Even without any special operators this can be ordered easily.
And the code needed to find parent nodes and child nodes exists.

--
greg

Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Thu, Feb 10, 2005 at 07:34:07PM -0500, Tom Lane wrote:
> Martijn van Oosterhout <kleptog@svana.org> writes:
> > I've been wondering about that. A while ago the change was made from
> > outputting a NOTICE with the EXPLAIN output to returning a resultset.
> > If you could agree on what columns to return it might not be so hard
> > for the EXPLAIN to return full tuples...
>
> The major stumbling block to that is that a table is inherently
> unordered, so you'd have to devise a labeling scheme to allow the
> node-tree structure to be represented properly.  And without WITH or
> CONNECT BY, it'd be a bit of a PITA for an application to decipher the
> labeling scheme again ...

To be honest, I'm not sure this a real problem. You could simply label
the first columns a rownumber and a depth number. In extreme cases you
might want a nodeid and an parent nodeid.

But IMHO I don't think people are going to be doing analysis on the
results from SQL. Much easier to just load the result into a perl (or
some other PL) script and process it there. Maybe when WITH and CONNECT
BY show up the capability should be there, but for now just returning
the data should be fine.

At the moment people are talking about parsing strings to get the
output. That output has the same issues as what's being proposed here,
we're just saving the parsing step.

However, tuple based output would be quite unreadable for humans, how
can one specify which output to return. EXPLAIN ANALYZE WITH TUPLES
query?

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Thu, Feb 10, 2005 at 10:30:26PM -0500, Tom Lane wrote:
> Well, the point is that there are potentially three types of statements
> involved:
>
>     1. SELECTs
>     2. Utility statements that can return tuples (EXPLAIN, SHOW, etc)
>     3. Utility statements that can't return tuples (ALTER, etc)

<snip>

> The $64 question is whether anyone *needs* to make these distinctions.
> If we arrange to return SPI_OK_SELECT for category 2, then callers won't
> be able to tell the difference between categories 1 and 2, but on the
> other hand a zero-row result set will still be properly classified as
> a SELECT-like operation.  If we leave the API as it stands today then a
> zero-row result set looks like a category 3, which arguably is a worse
> categorization.

It occurs to me that distinguishing between 2 and 3 would be useful,
since knowing if there were zero rows returned or nothing should be
returned is a useful distinction. But in the general case, cases 1 and
2 can be distinguished by examining the sent query.

I guess it turns out that "type-of-statement" and "returns-tuples" are
orthoganal concepts and nobody realised this at the time.

> I'm not sure that any of the statements in question actually can return
> zero-row result sets today, but I think it would be bad to make these
> decisions on the basis of assuming that the case will never arise.

What's the right response to "SHOW nonexistant_variable;" ? Currently
it's an error return, which seems reasonable.

I can imagine that there are situations where it would be useful to be
able to extract the output of VACUUM and ANALYZE as resultsets.
However, there's no way for a client to signal it wants a result set.
And just changing the output stops it being logged.

Not an easy choice.

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
Greg Stark
Date:
Tom Lane <tgl@sss.pgh.pa.us> writes:

> Well, the point is that there are potentially three types of statements
> involved:
>
>     1. SELECTs
>     2. Utility statements that can return tuples (EXPLAIN, SHOW, etc)
>     3. Utility statements that can't return tuples (ALTER, etc)

I'm not sure this matters, but of course there are other non-utility
statements like UPDATE and DELETE. Does SPI return SPI_OK_SELECT for those?

Because you can definitely do "EXPLAIN ANALYZE UPDATE ..." or "EXPLAIN ANALYZE
DELETE ...".

--
greg

Re: Understanding EXPLAIN ANALYZE output

From
Harald Fuchs
Date:
In article <20050211115856.GB7055@svana.org>,
Martijn van Oosterhout <kleptog@svana.org> writes:

> To be honest, I'm not sure this a real problem. You could simply label
> the first columns a rownumber and a depth number.

[See below ]

> At the moment people are talking about parsing strings to get the
> output. That output has the same issues as what's being proposed here,
> we're just saving the parsing step.

Yes, but whenever I need to parse "prose", I think there's something
wrong.  The textual EXPLAIN output is fine only for short query plans.

> However, tuple based output would be quite unreadable for humans, how
> can one specify which output to return. EXPLAIN ANALYZE WITH TUPLES
> query?

Going from tuples to prose is easy; there could be several formatting
functions for that - maybe even one which outputs the plan in a way
compatible to Oracle or something else.

If someone's interested, here's my "prose parser" again, now also
calculating the nesting depth:

CREATE TYPE expl_t AS (
  id INT,
  level INT,
  type TEXT,
  relation TEXT,
  cost1 FLOAT,
  cost2 FLOAT,
  rows INT,
  width INT,
  atime1 FLOAT,
  atime2 FLOAT,
  arows INT,
  loops INT,
  cont TEXT
);

CREATE OR REPLACE FUNCTION pg_explain(TEXT) RETURNS SETOF expl_t AS $$
  my $sql = $_[0];
  my $rv = spi_exec_query('SELECT current_database()');
  my $db = $rv->{rows}[0]->{current_database};
  # Grab EXPLAIN output
  use strict;
  use warnings;
  use DBI;
  my $dbh = DBI->connect("DBI:Pg:dbname=$db", "", "", {
    AutoCommit => 0,
    PrintError => 0,
    RaiseError => 1,
  });
  my $sth = $dbh->prepare("EXPLAIN ANALYZE $sql");
  $sth->execute();
  my @res = ();
  my @nm = qw(type relation cost1 cost2 rows width atime1 atime2 arows loops);
  my $cnt = 0;
  my @plen = (0);
  while (my $res = $sth->fetchrow_arrayref) {
    $cnt++;
    my @a = $res->[0] =~ m{^
      (?:(\s+)->\s\s)?              # Prefix
      (\S+(?:\s\S+)?)               # Operation
      (?:\son\s(\S+)(?:\s\S+)?)?    # on table [alias]
      \s\s                          # Estimations:
      \(cost=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\swidth=(\d+)\)
      \s                            # Actual values:
      \(actual\stime=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\sloops=(\d+)\)
    $}x;
    unless (@a) {
      $_ = $res->[0];
      next if /^Total runtime: \d+\.\d+ ms$/;
      s/^\s+//;
      $res[$#res]->{cont} = $_;
      next;
    }
    my $pref = shift @a || "";
    my $pl = length $pref;
    # Process prefix
    my $lvl = 0;
    if ($pl > $plen[$#plen]) {
      push @plen, $pl;
      $lvl = $#plen;
    } else {
      for my $ix (0 .. $#plen) {
        next unless $plen[$ix] == $pl;
        $lvl = $ix;
        last;
      }
    }
    my %elt = (id => $cnt, level => $lvl);
    $elt{$nm[$_]} = $a[$_] for (0..$#nm);
    push @res, \%elt;
  }
  $dbh->disconnect;
  return \@res;
$$ LANGUAGE "plperlu";

Re: Understanding EXPLAIN ANALYZE output

From
Martijn van Oosterhout
Date:
On Fri, Feb 11, 2005 at 03:50:05PM +0100, Harald Fuchs wrote:
> In article <20050211115856.GB7055@svana.org>,
> Martijn van Oosterhout <kleptog@svana.org> writes:
> > At the moment people are talking about parsing strings to get the
> > output. That output has the same issues as what's being proposed here,
> > we're just saving the parsing step.
>
> Yes, but whenever I need to parse "prose", I think there's something
> wrong.  The textual EXPLAIN output is fine only for short query plans.

I agree. I'm wondering if it is possible to write a function to produce
the alterbate output. I havn't looked at that code in a while.

> > However, tuple based output would be quite unreadable for humans, how
> > can one specify which output to return. EXPLAIN ANALYZE WITH TUPLES
> > query?
>
> Going from tuples to prose is easy; there could be several formatting
> functions for that - maybe even one which outputs the plan in a way
> compatible to Oracle or something else.
>
> If someone's interested, here's my "prose parser" again, now also
> calculating the nesting depth:

<snip>

There's one corner case you need to make sure you handle. In the plan
that started this thread there's a query node marked (never executed).
That will affect yout regex a bit. an that case you should probably
return NULLs. (It might do that, I havn't run the code through
carefully).

Case in point to why it should be an internal function.

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
> tool for doing 5% of the work and then sitting around waiting for someone
> else to do the other 95% so you can sue them.

Attachment

Re: Understanding EXPLAIN ANALYZE output

From
Harald Fuchs
Date:
In article <20050211222117.GF7055@svana.org>,
Martijn van Oosterhout <kleptog@svana.org> writes:

> There's one corner case you need to make sure you handle. In the plan
> that started this thread there's a query node marked (never executed).
> That will affect yout regex a bit. an that case you should probably
> return NULLs. (It might do that, I havn't run the code through
> carefully).

Ah, good point.  Here's a version which should do that.  It also tries
to extract the index name.

------------------------ snip snip snipety-snip --------------------------

CREATE TYPE expl_t AS (
  id INT,
  level INT,
  type TEXT,
  indx TEXT,
  relation TEXT,
  cost1 FLOAT,
  cost2 FLOAT,
  rows INT,
  width INT,
  atime1 FLOAT,
  atime2 FLOAT,
  arows INT,
  loops INT,
  cont TEXT
);

CREATE OR REPLACE FUNCTION pg_explain_analyze(TEXT) RETURNS SETOF expl_t AS $$
  my $sql = $_[0];
  my $rv = spi_exec_query('SELECT current_database()');
  my $db = $rv->{rows}[0]->{current_database};
  # Grab EXPLAIN output
  use strict;
  use warnings;
  use DBI;
  my $dbh = DBI->connect("DBI:Pg:dbname=$db", "", "", {
    AutoCommit => 0,
    PrintError => 0,
    RaiseError => 1,
  });
  my $sth = $dbh->prepare("EXPLAIN ANALYZE $sql");
  $sth->execute();
  my @res = ();
  my @nm = qw(type indx relation cost1 cost2 rows width atime1 atime2 arows loops);
  my $cnt = 0;
  my @plen = (0);
  while (my $res = $sth->fetchrow_arrayref) {
    $cnt++;
    my @a = $res->[0] =~ m{^
      (?:(\s+)->\s\s)?              # Prefix
      (\S+(?:\s\S+)?)               # Operation
      (?:\susing\s(.+?))?           # Index Scan using ixname
      (?:\son\s(\S+)(?:\s\S+)?)?    # on table [alias]
      \s\s                          # Estimations:
      \(cost=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\swidth=(\d+)\)
      \s                            # Actual values:
      \((.+?)\)
    $}x;
    unless (@a) {
      $_ = $res->[0];
      next if /^Total runtime: \d+\.\d+ ms$/;
      s/^\s+//;
      if (defined $res[$#res]->{cont}) {
        $res[$#res]->{cont} .= ", $_";
      } else {
        $res[$#res]->{cont} = $_;
      }
      next;
    }
    my @x = $a[8] =~ m{actual\stime=(\d+\.\d+)\.\.(\d+\.\d+)\srows=(\d+)\sloops=(\d+)$};
    splice @a, 8, 1, @x;
    my $pref = shift @a || "";
    my $pl = length $pref;
    # Process prefix
    my $lvl = 0;
    if ($pl > $plen[$#plen]) {
      push @plen, $pl;
      $lvl = $#plen;
    } else {
      for my $ix (0 .. $#plen) {
        next unless $plen[$ix] == $pl;
        $lvl = $ix;
        last;
      }
    }
    my %elt = (id => $cnt, level => $lvl);
    $elt{$nm[$_]} = $a[$_] for (0..$#nm);
    push @res, \%elt;
  }
  $dbh->disconnect;
  return \@res;
$$ LANGUAGE "plperlu";