Thread: Weird query plan

Weird query plan

From
Dmitry Tkach
Date:
Hi, everybody!

Here is a weird problem, I ran into...
I have two huge (80 million rows each) tables (a and b), with id as a PK
on both of them and also an FK from b referencing a.
When I try to run a query like:

select * from a, b where a.id >=  7901288 and a.id=b.id limit 1;

The query takes *forever*.
If I do
select * from a,b where b.id >= 7901288 and a.id=b.id limit 1;

then it returns right away.

The query plan looks identical in both cases:

Limit  (cost=0.00..12.51 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1009772807.91 rows=80740598 width=8)
        ->  Index Scan using b_pkey on b  (cost=0.00..375410773.29
rows=80740598 width=4)
        ->  Index Scan using a_pkey on a  (cost=0.00..6.85 rows=1 width=4)

... which makes me think that it decides to use  b as the outer table
for both cases (which would obviously make it suck in the first one)... :-(

This happens on 7.2.4... I have a 7.3 database with the same schema, but
it is not populated with data, so I could not test it on 7.3...
I looked at the 7.3's query plans though, and they look better to me:

 Limit  (cost=0.00..4.97 rows=1 width=8)
   ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
         ->  Index Scan using b_pkey on b  (cost=0.00..45.50 rows=333
width=4)
               Index Cond: (id >= 7901288)
         ->  Index Scan using a_pkey on a  (cost=0.00..4.82 rows=1 width=4)
               Index Cond: (a.id = "outer".id)

in the second case, and

 Limit  (cost=0.00..4.97 rows=1 width=8)
   ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
         ->  Index Scan using a_pkey on a  (cost=0.00..45.50 rows=333
width=4)
               Index Cond: (id >= 7901288)
         ->  Index Scan using b_pkey on b  (cost=0.00..4.82 rows=1 width=4)
               Index Cond: ("outer".id = b.id)

in the first case... (looks like it does swap them around as I expected)...

Do you know of anything that got fixed between 7.2.4 and 7.3, related to
this problem?

I also noticed that changing a,b to b,a in the from clause doesn't
affect anything... and (what's even more weird) even using an explicit
join doesn't help:


explain select a.duns from a natural join b dm where a.id >= 7901288
limit 1;
NOTICE:  QUERY PLAN:

Limit  (cost=0.00..12.78 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1023061272.15 rows=80049919 width=8)
        ->  Index Scan using b_pkey on b  (cost=0.00..380070641.01
rows=81786784 width=4)
        ->  Index Scan using a_pkey on a  (cost=0.00..6.86 rows=1 width=4)

:-(

Any ideas?

Thanks a lot!

Dima





Re: Weird query plan

From
Tom Lane
Date:
Dmitry Tkach <dmitry@openratings.com> writes:
> The query plan looks identical in both cases:

> Limit  (cost=0.00..12.51 rows=1 width=8)
>   ->  Nested Loop  (cost=0.00..1009772807.91 rows=80740598 width=8)
>         ->  Index Scan using b_pkey on b  (cost=0.00..375410773.29
> rows=80740598 width=4)
>         ->  Index Scan using a_pkey on a  (cost=0.00..6.85 rows=1 width=4)

> ... which makes me think that it decides to use  b as the outer table
> for both cases (which would obviously make it suck in the first one)... :-(

That's what it says, all right, which seems odd to me.  Are you sure you
looked at the right plans?

> This happens on 7.2.4... I have a 7.3 database with the same schema, but
> it is not populated with data, so I could not test it on 7.3...

I could not reproduce a problem on 7.2.4.  I get (using toy tables, and
suppressing the planner's urge to use mergejoin instead)

lo=# explain select * from a, b where a.id >=  7901288 and a.id=b.id limit 1;
NOTICE:  QUERY PLAN:

Limit  (cost=0.00..4.97 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
        ->  Index Scan using a_pkey on a  (cost=0.00..45.50 rows=333 width=4)
        ->  Index Scan using b_pkey on b  (cost=0.00..4.82 rows=1 width=4)

EXPLAIN
lo=# explain select * from a, b where b.id >=  7901288 and a.id=b.id limit 1;
NOTICE:  QUERY PLAN:

Limit  (cost=0.00..4.97 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
        ->  Index Scan using b_pkey on b  (cost=0.00..45.50 rows=333 width=4)
        ->  Index Scan using a_pkey on a  (cost=0.00..4.82 rows=1 width=4)

EXPLAIN

which looks like the right thing.

            regards, tom lane

Re: Weird query plan

From
Dmitry Tkach
Date:
Hmmm...
Indeed. I tried it in 7.2.4 on a couple of empty tables, and it does do
the right thing...
Also, I have another copy (not exact copy, but identical schema, and
similar content... but about twice smaller) of the original database...
I tried my query on it, and it works right too.
So, there must be something wrong with that particular database I suppose...

Any ideas what I should look at?

Thanks a lot!

Dima

Tom Lane wrote:

>Dmitry Tkach <dmitry@openratings.com> writes:
>
>
>>The query plan looks identical in both cases:
>>
>>
>
>
>
>>Limit  (cost=0.00..12.51 rows=1 width=8)
>>  ->  Nested Loop  (cost=0.00..1009772807.91 rows=80740598 width=8)
>>        ->  Index Scan using b_pkey on b  (cost=0.00..375410773.29
>>rows=80740598 width=4)
>>        ->  Index Scan using a_pkey on a  (cost=0.00..6.85 rows=1 width=4)
>>
>>
>
>
>
>>... which makes me think that it decides to use  b as the outer table
>>for both cases (which would obviously make it suck in the first one)... :-(
>>
>>
>
>That's what it says, all right, which seems odd to me.  Are you sure you
>looked at the right plans?
>
>
>
>>This happens on 7.2.4... I have a 7.3 database with the same schema, but
>>it is not populated with data, so I could not test it on 7.3...
>>
>>
>
>I could not reproduce a problem on 7.2.4.  I get (using toy tables, and
>suppressing the planner's urge to use mergejoin instead)
>
>lo=# explain select * from a, b where a.id >=  7901288 and a.id=b.id limit 1;
>NOTICE:  QUERY PLAN:
>
>Limit  (cost=0.00..4.97 rows=1 width=8)
>  ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
>        ->  Index Scan using a_pkey on a  (cost=0.00..45.50 rows=333 width=4)
>        ->  Index Scan using b_pkey on b  (cost=0.00..4.82 rows=1 width=4)
>
>EXPLAIN
>lo=# explain select * from a, b where b.id >=  7901288 and a.id=b.id limit 1;
>NOTICE:  QUERY PLAN:
>
>Limit  (cost=0.00..4.97 rows=1 width=8)
>  ->  Nested Loop  (cost=0.00..1657.34 rows=333 width=8)
>        ->  Index Scan using b_pkey on b  (cost=0.00..45.50 rows=333 width=4)
>        ->  Index Scan using a_pkey on a  (cost=0.00..4.82 rows=1 width=4)
>
>EXPLAIN
>
>which looks like the right thing.
>
>            regards, tom lane
>
>



Re: Weird query plan

From
Tom Lane
Date:
Dmitry Tkach <dmitry@openratings.com> writes:
> Also, I have another copy (not exact copy, but identical schema, and
> similar content... but about twice smaller) of the original database...
> I tried my query on it, and it works right too.

> So, there must be something wrong with that particular database I suppose...

Hmm.  Take a look at the pg_stats statistics for the id columns in each
case.  Could the ones for the misbehaving tables be out of whack
somehow?  I'm wondering for example if the planner discounted the >=
condition because it thought it would match all the rows.

            regards, tom lane

Re: Weird query plan

From
Dmitry Tkach
Date:
Tom Lane wrote:

>Dmitry Tkach <dmitry@openratings.com> writes:
>
>
>>Also, I have another copy (not exact copy, but identical schema, and
>>similar content... but about twice smaller) of the original database...
>>I tried my query on it, and it works right too.
>>
>>
>
>
>
>>So, there must be something wrong with that particular database I suppose...
>>
>>
>
>Hmm.  Take a look at the pg_stats statistics for the id columns in each
>case.  Could the ones for the misbehaving tables be out of whack
>somehow?  I'm wondering for example if the planner discounted the >=
>condition because it thought it would match all the rows.
>
>
>
Well... It *does* match (almost) all the rows (there are about a million
rows before that key, and the remaining 79 mil after)...
The stats look in synch with that:

for a:
stavalues1  |
{1000488,33495482,69111011,99286820,129611281,204441828,331968789,508451171,782660252,869480434,989787700}
for b:
stavalues1  |
{1008692,54892364,110119463,192551141,300490851,389609207,465139533,570442801,706876547,849087358,989851076}

(The key in the criteria was 7901288 - somewhere in the first bucket)


*But* isn't  my 'limit' clause supposed to affect that decision? I mean,
even though the filter isn't very selective, it should still speed up
getting the *first* match...


Thanks!

Dima

P.S. I also tried to look at the stats of that other database I
mentioned... The stats for b look similar:
stavalues1  |
{1028104,25100079,50685614,78032989,105221902,135832793,199827486,611968165,807597786,884897604,969971779}

But the stats for a are just *not there at all* (is it even possible?)
Could it be the reason why it works on that database (because it uses
the default stats instead of the real thing)?




Re: Weird query plan

From
Dmitry Tkach
Date:
> P.S. I also tried to look at the stats of that other database I
> mentioned... The stats for b look similar:
> stavalues1  |
> {1028104,25100079,50685614,78032989,105221902,135832793,199827486,611968165,807597786,884897604,969971779}
>
>
> But the stats for a are just *not there at all* (is it even possible?)
> Could it be the reason why it works on that database (because it uses
> the default stats instead of the real thing)?
>


I  ran 'analyze a;' on that database...
I now have the same problem with it, but the other way around - the
query with a condition on a  runs quickly, and one with a condition on b
does not... and the query plans are the same, and have a as outer table...
The new stats for a look like:


stavalues1  |
{1003284,61663485,126262679,211106732,300624079,392709544,469196539,572479496,697890767,842087009,989170923}


... but actually, I never tried it with a condition on b on that
database before analyze :-(
I just tried the "a - variant" (the one that wasn't working originally),
and it worked...
Now, I tried deleting all the entries for a from pg_statistic, and
running the b-variant... and it still doesn't work.

So, it probably has nothing to do with that analyze I ran...

Dima


Re: Weird query plan

From
Tom Lane
Date:
Dmitry Tkach <dmitry@openratings.com> writes:
> I now have the same problem with it, but the other way around - the
> query with a condition on a  runs quickly, and one with a condition on b
> does not... and the query plans are the same, and have a as outer table...

Hm.  You know, I wonder whether the query plans really are the same.
One of the reasons why 7.3 and later show the qual conditions is that
it was too easy to fall into the trap of assuming that plans of the same
structure had the same conditions.  Try doing "explain verbose" and look
to see if the plans look the same at that level of detail.

            regards, tom lane

Re: Weird query plan

From
Dmitry Tkach
Date:
Tom Lane wrote:

>Dmitry Tkach <dmitry@openratings.com> writes:
>
>
>>I now have the same problem with it, but the other way around - the
>>query with a condition on a  runs quickly, and one with a condition on b
>>does not... and the query plans are the same, and have a as outer table...
>>
>>
>
>Hm.  You know, I wonder whether the query plans really are the same.
>One of the reasons why 7.3 and later show the qual conditions is that
>it was too easy to fall into the trap of assuming that plans of the same
>structure had the same conditions.  Try doing "explain verbose" and look
>to see if the plans look the same at that level of detail.
>
>            regards, tom lane
>
>
I am afraid that's too much detail for me to look at :-)
I have no clue what all that stuff means :-(

But I am pretty sure they are the same - I did not know whether the
first one or the second was supposed to be the outer relation, so I
looked at it in the debugger...
So, I know that in both cases it was using b for the outer loop...

Thanks!
Dima


Re: Weird query plan

From
Dmitry Tkach
Date:
Here is that verbose output, if it is of any help:

prod=# explain verbose select a.id from a, b where a.id >= 7901288 and
b.id=a.id limit 1;
NOTICE:  QUERY DUMP:

{ LIMIT :startup_cost 0.00 :total_cost 12.78 :rows 1 :width 8
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
:restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 1 :varattno 1 :vartype 23 :vartypmod
-1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <> :lefttree {
NESTLOOP :startup_cost 0.00 :total_cost 1023061272.15 :rows 80049919
:width 8 :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype
23 :restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 65000 :varattno 1 :vartype 23
:vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <>
:lefttree { INDEXSCAN :startup_cost 0.00 :total_cost 380070641.01 :rows
81786784 :width 4 :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1
:restype 23 :restypmod -1 :resname <> :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 2 :varattno 1
:vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno 1}})
:qpqual <> :lefttree <> :righttree <> :extprm () :locprm () :initplan <>
:nprm 0  :scanrelid 2 :indxid ( 708140136) :indxqual (<>) :indxqualorig
(<>) :indxorderdir 1 } :righttree { INDEXSCAN :startup_cost 0.00
:total_cost 6.86 :rows 1 :width 4 :qptargetlist ({ TARGETENTRY :resdom {
RESDOM :resno 1 :restype 23 :restypmod -1 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
:varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1
:varoattno 1}}) :qpqual <> :lefttree <> :righttree <> :extprm () :locprm
() :initplan <> :nprm 0  :scanrelid 1 :indxid ( 1074605180) :indxqual
(({ EXPR :typeOid 16  :opType op :oper { OPER :opno 96 :opid 65
:opresulttype 16 } :args ({ VAR :varno 1 :varattno 1 :vartype 23
:vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1} { VAR :varno
65001 :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 2
:varoattno 1})} { EXPR :typeOid 16  :opType op :oper { OPER :opno 525
:opid 150 :opresulttype 16 } :args ({ VAR :varno 1 :varattno 1 :vartype
23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1} { CONST
:consttype 23 :constlen 4 :constbyval true :constisnull false
:constvalue  4 [ 104 -112 120 0 ] })})) :indxqualorig (({ EXPR :typeOid
16  :opType op :oper { OPER :opno 96 :opid 65 :opresulttype 16 } :args
({ VAR :varno 65001 :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup
0 :varnoold 2 :varoattno 1} { VAR :varno 1 :varattno 1 :vartype 23
:vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1})} { EXPR
:typeOid 16  :opType op :oper { OPER :opno 525 :opid 150 :opresulttype
16 } :args ({ VAR :varno 1 :varattno 1 :vartype 23 :vartypmod -1
:varlevelsup 0 :varnoold 1 :varoattno 1} { CONST :consttype 23 :constlen
4 :constbyval true :constisnull false :constvalue  4 [ 104 -112 120 0 ]
})})) :indxorderdir 0 } :extprm () :locprm () :initplan <> :nprm 0
:jointype 0 :joinqual <>} :righttree <> :extprm () :locprm () :initplan
<> :nprm 0  :limitOffset <> :limitCount { CONST :consttype 23 :constlen
4 :constbyval true :constisnull false :constvalue  4 [ 1 0 0 0 ] }}
NOTICE:  QUERY PLAN:

Limit  (cost=0.00..12.78 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1023061272.15 rows=80049919 width=8)
        ->  Index Scan using b_pkey on b  (cost=0.00..380070641.01
rows=81786784 width=4)
        ->  Index Scan using a_pkey on a  (cost=0.00..6.86 rows=1 width=4)

EXPLAIN
prod=# explain verbose select a.id from a,b where b.id >= 7901288 and
b.id=a.id limit 1;
NOTICE:  QUERY DUMP:

{ LIMIT :startup_cost 0.00 :total_cost 12.51 :rows 1 :width 8
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
:restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 1 :varattno 1 :vartype 23 :vartypmod
-1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <> :lefttree {
NESTLOOP :startup_cost 0.00 :total_cost 1009772807.91 :rows 80740598
:width 8 :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype
23 :restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 65000 :varattno 1 :vartype 23
:vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <>
:lefttree { INDEXSCAN :startup_cost 0.00 :total_cost 375410773.29 :rows
80740598 :width 4 :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1
:restype 23 :restypmod -1 :resname <> :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 2 :varattno 1
:vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno 1}})
:qpqual <> :lefttree <> :righttree <> :extprm () :locprm () :initplan <>
:nprm 0  :scanrelid 2 :indxid ( 708140136) :indxqual (({ EXPR :typeOid
16  :opType op :oper { OPER :opno 525 :opid 150 :opresulttype 16 } :args
({ VAR :varno 2 :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0
:varnoold 2 :varoattno 1} { CONST :consttype 23 :constlen 4 :constbyval
true :constisnull false :constvalue  4 [ 104 -112 120 0 ] })}))
:indxqualorig (({ EXPR :typeOid 16  :opType op :oper { OPER :opno 525
:opid 150 :opresulttype 16 } :args ({ VAR :varno 2 :varattno 1 :vartype
23 :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno 1} { CONST
:consttype 23 :constlen 4 :constbyval true :constisnull false
:constvalue  4 [ 104 -112 120 0 ] })})) :indxorderdir 1 } :righttree {
INDEXSCAN :startup_cost 0.00 :total_cost 6.85 :rows 1 :width 4
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
:restypmod -1 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 1 :varattno 1 :vartype 23 :vartypmod
-1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <> :lefttree <>
:righttree <> :extprm () :locprm () :initplan <> :nprm 0  :scanrelid 1
:indxid ( 1074605180) :indxqual (({ EXPR :typeOid 16  :opType op :oper {
OPER :opno 96 :opid 65 :opresulttype 16 } :args ({ VAR :varno 1
:varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1
:varoattno 1} { VAR :varno 65001 :varattno 1 :vartype 23 :vartypmod -1
:varlevelsup 0 :varnoold 2 :varoattno 1})})) :indxqualorig (({ EXPR
:typeOid 16  :opType op :oper { OPER :opno 96 :opid 65 :opresulttype 16
} :args ({ VAR :varno 65001 :varattno 1 :vartype 23 :vartypmod -1
:varlevelsup 0 :varnoold 2 :varoattno 1} { VAR :varno 1 :varattno 1
:vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1})}))
:indxorderdir 0 } :extprm () :locprm () :initplan <> :nprm 0  :jointype
0 :joinqual <>} :righttree <> :extprm () :locprm () :initplan <> :nprm
0  :limitOffset <> :limitCount { CONST :consttype 23 :constlen 4
:constbyval true :constisnull false :constvalue  4 [ 1 0 0 0 ] }}
NOTICE:  QUERY PLAN:

Limit  (cost=0.00..12.51 rows=1 width=8)
  ->  Nested Loop  (cost=0.00..1009772807.91 rows=80740598 width=8)
        ->  Index Scan using b_pkey on b  (cost=0.00..375410773.29
rows=80740598 width=4)
        ->  Index Scan using a_pkey on a  (cost=0.00..6.85 rows=1 width=4)

EXPLAIN


Dmitry Tkach wrote:

> Tom Lane wrote:
>
>> Dmitry Tkach <dmitry@openratings.com> writes:
>>
>>
>>> I now have the same problem with it, but the other way around - the
>>> query with a condition on a  runs quickly, and one with a condition
>>> on b does not... and the query plans are the same, and have a as
>>> outer table...
>>>
>>
>>
>> Hm.  You know, I wonder whether the query plans really are the same.
>> One of the reasons why 7.3 and later show the qual conditions is that
>> it was too easy to fall into the trap of assuming that plans of the same
>> structure had the same conditions.  Try doing "explain verbose" and look
>> to see if the plans look the same at that level of detail.
>>
>>             regards, tom lane
>>
>>
> I am afraid that's too much detail for me to look at :-)
> I have no clue what all that stuff means :-(
>
> But I am pretty sure they are the same - I did not know whether the
> first one or the second was supposed to be the outer relation, so I
> looked at it in the debugger...
> So, I know that in both cases it was using b for the outer loop...
>
> Thanks!
> Dima
>



Re: Weird query plan

From
Alvaro Herrera
Date:
On Wed, Sep 17, 2003 at 04:39:59PM -0400, Dmitry Tkach wrote:
> Here is that verbose output, if it is of any help:
>
> prod=# explain verbose select a.id from a, b where a.id >= 7901288 and
> b.id=a.id limit 1;
> NOTICE:  QUERY DUMP:

[etc]

Maybe you can try the indented version and do the comparison using diff?

--
Alvaro Herrera (<alvherre[a]dcc.uchile.cl>)
"Hoy es el primer dia del resto de mi vida"

Re: Weird query plan

From
Tom Lane
Date:
Dmitry Tkach <dmitry@openratings.com> writes:
>> Hm.  You know, I wonder whether the query plans really are the same.
>> One of the reasons why 7.3 and later show the qual conditions is that
>> it was too easy to fall into the trap of assuming that plans of the same
>> structure had the same conditions.  Try doing "explain verbose" and look
>> to see if the plans look the same at that level of detail.

> I am afraid that's too much detail for me to look at :-)
> I have no clue what all that stuff means :-(

Well, "diff" would've been enough to tell you they are different.  It
looks to me like in the slow case the query plan is of the form

Limit
  ->  Nested Loop
        ->  Index Scan using a_pkey on a
        <<no index condition, ie full table scan>>
        ->  Index Scan using b_pkey on b
        b.id >= 7901288 and b.id = "outer".id

which is a pretty silly plan to arrive at; are you by any chance running
with enable_seqscan = off?

I'm not certain why 7.2 would be picking this plan, esp. given that it
is capable of generating the better plan.  It might be that it's got
something to do with the low selectivity of the id >= 7901288 clause.
In any case, if it's fixed in 7.3 I'm not going to worry too much about
it ...

            regards, tom lane

Re: Weird query plan

From
Dennis Gearon
Date:
There isn't a formatter for these plans is there? Or some template for a
unix editor that will format it?

Dmitry Tkach wrote:

> Here is that verbose output, if it is of any help:
>
> prod=# explain verbose select a.id from a, b where a.id >= 7901288 and
> b.id=a.id limit 1;
> NOTICE:  QUERY DUMP:
>
> { LIMIT :startup_cost 0.00 :total_cost 12.78 :rows 1 :width 8
> :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
> :restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
> :resjunk false } :expr { VAR :varno 1 :varattno 1 :vartype 23
> :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <>
> :lefttree { NESTLOOP :startup_cost 0.00 :total_cost 1023061272.15
> :rows 80049919 :width 8 :qptargetlist ({ TARGETENTRY :resdom { RESDOM
> :resno 1 :restype 23 :restypmod -1 :resname duns :reskey 0 :reskeyop 0
> :ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000 :varattno
> 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno
> 1}}) :qpqual <> :lefttree { INDEXSCAN :startup_cost 0.00 :total_cost
> 380070641.01 :rows 81786784 :width 4 :qptargetlist ({ TARGETENTRY
> :resdom { RESDOM :resno 1 :restype 23 :restypmod -1 :resname <>
> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR
> :varno 2 :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0
> :varnoold 2 :varoattno 1}}) :qpqual <> :lefttree <> :righttree <>
> :extprm () :locprm () :initplan <> :nprm 0  :scanrelid 2 :indxid (
> 708140136) :indxqual (<>) :indxqualorig (<>) :indxorderdir 1 }
> :righttree { INDEXSCAN :startup_cost 0.00 :total_cost 6.86 :rows 1
> :width 4 :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1
> :restype 23 :restypmod -1 :resname <> :reskey 0 :reskeyop 0
> :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1 :varattno 1
> :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1}})
> :qpqual <> :lefttree <> :righttree <> :extprm () :locprm () :initplan
> <> :nprm 0  :scanrelid 1 :indxid ( 1074605180) :indxqual (({ EXPR
> :typeOid 16  :opType op :oper { OPER :opno 96 :opid 65 :opresulttype
> 16 } :args ({ VAR :varno 1 :varattno 1 :vartype 23 :vartypmod -1
> :varlevelsup 0 :varnoold 1 :varoattno 1} { VAR :varno 65001 :varattno
> 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno
> 1})} { EXPR :typeOid 16  :opType op :oper { OPER :opno 525 :opid 150
> :opresulttype 16 } :args ({ VAR :varno 1 :varattno 1 :vartype 23
> :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1} { CONST
> :consttype 23 :constlen 4 :constbyval true :constisnull false
> :constvalue  4 [ 104 -112 120 0 ] })})) :indxqualorig (({ EXPR
> :typeOid 16  :opType op :oper { OPER :opno 96 :opid 65 :opresulttype
> 16 } :args ({ VAR :varno 65001 :varattno 1 :vartype 23 :vartypmod -1
> :varlevelsup 0 :varnoold 2 :varoattno 1} { VAR :varno 1 :varattno 1
> :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1})}
> { EXPR :typeOid 16  :opType op :oper { OPER :opno 525 :opid 150
> :opresulttype 16 } :args ({ VAR :varno 1 :varattno 1 :vartype 23
> :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1} { CONST
> :consttype 23 :constlen 4 :constbyval true :constisnull false
> :constvalue  4 [ 104 -112 120 0 ] })})) :indxorderdir 0 } :extprm ()
> :locprm () :initplan <> :nprm 0  :jointype 0 :joinqual <>} :righttree
> <> :extprm () :locprm () :initplan <> :nprm 0  :limitOffset <>
> :limitCount { CONST :consttype 23 :constlen 4 :constbyval true
> :constisnull false :constvalue  4 [ 1 0 0 0 ] }}
> NOTICE:  QUERY PLAN:
>
> Limit  (cost=0.00..12.78 rows=1 width=8)
>  ->  Nested Loop  (cost=0.00..1023061272.15 rows=80049919 width=8)
>        ->  Index Scan using b_pkey on b  (cost=0.00..380070641.01
> rows=81786784 width=4)
>        ->  Index Scan using a_pkey on a  (cost=0.00..6.86 rows=1 width=4)
>
> EXPLAIN
> prod=# explain verbose select a.id from a,b where b.id >= 7901288 and
> b.id=a.id limit 1;
> NOTICE:  QUERY DUMP:
>
> { LIMIT :startup_cost 0.00 :total_cost 12.51 :rows 1 :width 8
> :qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
> :restypmod -1 :resname duns :reskey 0 :reskeyop 0 :ressortgroupref 0
> :resjunk false } :expr { VAR :varno 1 :varattno 1 :vartype 23
> :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <>
> :lefttree { NESTLOOP :startup_cost 0.00 :total_cost 1009772807.91
> :rows 80740598 :width 8 :qptargetlist ({ TARGETENTRY :resdom { RESDOM
> :resno 1 :restype 23 :restypmod -1 :resname duns :reskey 0 :reskeyop 0
> :ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000 :varattno
> 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1 :varoattno
> 1}}) :qpqual <> :lefttree { INDEXSCAN :startup_cost 0.00 :total_cost
> 375410773.29 :rows 80740598 :width 4 :qptargetlist ({ TARGETENTRY
> :resdom { RESDOM :resno 1 :restype 23 :restypmod -1 :resname <>
> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR
> :varno 2 :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0
> :varnoold 2 :varoattno 1}}) :qpqual <> :lefttree <> :righttree <>
> :extprm () :locprm () :initplan <> :nprm 0  :scanrelid 2 :indxid (
> 708140136) :indxqual (({ EXPR :typeOid 16  :opType op :oper { OPER
> :opno 525 :opid 150 :opresulttype 16 } :args ({ VAR :varno 2 :varattno
> 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno 1}
> { CONST :consttype 23 :constlen 4 :constbyval true :constisnull false
> :constvalue  4 [ 104 -112 120 0 ] })})) :indxqualorig (({ EXPR
> :typeOid 16  :opType op :oper { OPER :opno 525 :opid 150 :opresulttype
> 16 } :args ({ VAR :varno 2 :varattno 1 :vartype 23 :vartypmod -1
> :varlevelsup 0 :varnoold 2 :varoattno 1} { CONST :consttype 23
> :constlen 4 :constbyval true :constisnull false :constvalue  4 [ 104
> -112 120 0 ] })})) :indxorderdir 1 } :righttree { INDEXSCAN
> :startup_cost 0.00 :total_cost 6.85 :rows 1 :width 4 :qptargetlist ({
> TARGETENTRY :resdom { RESDOM :resno 1 :restype 23 :restypmod -1
> :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
> :expr { VAR :varno 1 :varattno 1 :vartype 23 :vartypmod -1
> :varlevelsup 0 :varnoold 1 :varoattno 1}}) :qpqual <> :lefttree <>
> :righttree <> :extprm () :locprm () :initplan <> :nprm 0  :scanrelid 1
> :indxid ( 1074605180) :indxqual (({ EXPR :typeOid 16  :opType op :oper
> { OPER :opno 96 :opid 65 :opresulttype 16 } :args ({ VAR :varno 1
> :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1
> :varoattno 1} { VAR :varno 65001 :varattno 1 :vartype 23 :vartypmod
> -1  :varlevelsup 0 :varnoold 2 :varoattno 1})})) :indxqualorig (({
> EXPR :typeOid 16  :opType op :oper { OPER :opno 96 :opid 65
> :opresulttype 16 } :args ({ VAR :varno 65001 :varattno 1 :vartype 23
> :vartypmod -1  :varlevelsup 0 :varnoold 2 :varoattno 1} { VAR :varno 1
> :varattno 1 :vartype 23 :vartypmod -1  :varlevelsup 0 :varnoold 1
> :varoattno 1})})) :indxorderdir 0 } :extprm () :locprm () :initplan <>
> :nprm 0  :jointype 0 :joinqual <>} :righttree <> :extprm () :locprm ()
> :initplan <> :nprm 0  :limitOffset <> :limitCount { CONST :consttype
> 23 :constlen 4 :constbyval true :constisnull false :constvalue  4 [ 1
> 0 0 0 ] }}
> NOTICE:  QUERY PLAN:
>
> Limit  (cost=0.00..12.51 rows=1 width=8)
>  ->  Nested Loop  (cost=0.00..1009772807.91 rows=80740598 width=8)
>        ->  Index Scan using b_pkey on b  (cost=0.00..375410773.29
> rows=80740598 width=4)
>        ->  Index Scan using a_pkey on a  (cost=0.00..6.85 rows=1 width=4)
>
> EXPLAIN
>
>
> Dmitry Tkach wrote:
>
>> Tom Lane wrote:
>>
>>> Dmitry Tkach <dmitry@openratings.com> writes:
>>>
>>>
>>>> I now have the same problem with it, but the other way around - the
>>>> query with a condition on a  runs quickly, and one with a condition
>>>> on b does not... and the query plans are the same, and have a as
>>>> outer table...
>>>>
>>>
>>>
>>>
>>> Hm.  You know, I wonder whether the query plans really are the same.
>>> One of the reasons why 7.3 and later show the qual conditions is that
>>> it was too easy to fall into the trap of assuming that plans of the
>>> same
>>> structure had the same conditions.  Try doing "explain verbose" and
>>> look
>>> to see if the plans look the same at that level of detail.
>>>
>>>             regards, tom lane
>>>
>>>
>> I am afraid that's too much detail for me to look at :-)
>> I have no clue what all that stuff means :-(
>>
>> But I am pretty sure they are the same - I did not know whether the
>> first one or the second was supposed to be the outer relation, so I
>> looked at it in the debugger...
>> So, I know that in both cases it was using b for the outer loop...
>>
>> Thanks!
>> Dima
>>
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 6: Have you searched our list archives?
>
>               http://archives.postgresql.org
>


Re: Weird query plan

From
Tom Lane
Date:
Dennis Gearon <gearond@fireserve.net> writes:
> There isn't a formatter for these plans is there?

Sure.  In 7.2 I think you have to set debug_pretty_print and then look
in the postmaster log (debug_pretty_print didn't affect client output
for some reason).  Later versions have progressively saner ways to get
the formatted results.

            regards, tom lane

Re: Weird query plan

From
Dmitry Tkach
Date:
Tom Lane wrote:

>Dmitry Tkach <dmitry@openratings.com> writes:
>
>
>>>Hm.  You know, I wonder whether the query plans really are the same.
>>>One of the reasons why 7.3 and later show the qual conditions is that
>>>it was too easy to fall into the trap of assuming that plans of the same
>>>structure had the same conditions.  Try doing "explain verbose" and look
>>>to see if the plans look the same at that level of detail.
>>>
>>>
>
>
>
>>I am afraid that's too much detail for me to look at :-)
>>I have no clue what all that stuff means :-(
>>
>>
>
>Well, "diff" would've been enough to tell you they are different.  It
>looks to me like in the slow case the query plan is of the form
>
>Limit
>  ->  Nested Loop
>        ->  Index Scan using a_pkey on a
>        <<no index condition, ie full table scan>>
>        ->  Index Scan using b_pkey on b
>        b.id >= 7901288 and b.id = "outer".id
>
>which is a pretty silly plan to arrive at; are you by any chance running
>with enable_seqscan = off?
>
Ummm... yes, I am.
Sorry, I should have mentioned that earlier...

>
>I'm not certain why 7.2 would be picking this plan, esp. given that it
>is capable of generating the better plan.  It might be that it's got
>something to do with the low selectivity of the id >= 7901288 clause.
>In any case, if it's fixed in 7.3 I'm not going to worry too much about
>it ...
>
>
>
I don't know that actually - the 7.3 database I tried it on when it
worked was empty .... I just assumed, that since it generated the right
query plan it would work...
But then, I fugured out that it worked in 7.2 as well when I tried it
with just two empty tables :-(


Dima