new BUG: "postgresql 9.2.3: very long query time"

Hi all,

Postgresql 9.2.3 is processing my query is much longer than Postgresql
9.1.8:
Postgresql 9.1.8 - *2292* ms
Postgresql 9.2.3 - *163336* ms

I provided my query in attach and the database dump too,
this bug is reproducible.

Operating system: Gentoo x86_64 Linux 2.6.36

On Wed, Feb 20, 2013 at 5:42 AM, Claude Speed <gta3user(at)gmail(dot)com> wrote:
> Postgresql 9.2.3 is processing my query is much longer than Postgresql
> 9.1.8:
> Postgresql 9.1.8 - 2292 ms
> Postgresql 9.2.3 - 163336 ms
>
> I provided my query in attach and the database dump too,
> this bug is reproducible.

1). Can you supply the EXPLAIN ANALYZE plans for both queries?
2). Have you ANALYZEd the relevant tables recently?
3). Maybe supply the results of this query too:

SELECT name, current_setting(name), source
FROM pg_settings
WHERE source NOT IN ('default', 'override')
UNION ALL
SELECT 'version' as name, version(), null;

On Wed, Feb 20, 2013 at 5:42 AM, Claude Speed <gta3user(at)gmail(dot)com> wrote:
> Hi all,
>
> Postgresql 9.2.3 is processing my query is much longer than Postgresql
> 9.1.8:
> Postgresql 9.1.8 - 2292 ms
> Postgresql 9.2.3 - 163336 ms
>
> I provided my query in attach and the database dump too,
> this bug is reproducible.
>
> Operating system: Gentoo x86_64 Linux 2.6.36

The slowness was introduced with this:

commit e2fa76d80ba571d4de8992de6386536867250474
Author: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Date: Fri Jan 27 19:26:38 2012 -0500

Use parameterized paths to generate inner indexscans more flexibly.

Do you know of simpler queries that also exhibits this behavior? It
would certainly make analysis of the issue easier.

Cheers,

Jeff

21.02.2013 21:25, Jeff Janes пишет:
> On Wed, Feb 20, 2013 at 5:42 AM, Claude Speed <gta3user(at)gmail(dot)com> wrote:
>> Hi all,
>>
>> Postgresql 9.2.3 is processing my query is much longer than Postgresql
>> 9.1.8:
>> Postgresql 9.1.8 - 2292 ms
>> Postgresql 9.2.3 - 163336 ms
>>
>> I provided my query in attach and the database dump too,
>> this bug is reproducible.
>>
>> Operating system: Gentoo x86_64 Linux 2.6.36
> The slowness was introduced with this:
>
> commit e2fa76d80ba571d4de8992de6386536867250474
> Author: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
> Date: Fri Jan 27 19:26:38 2012 -0500
>
> Use parameterized paths to generate inner indexscans more flexibly.
>
>
> Do you know of simpler queries that also exhibits this behavior? It
> would certainly make analysis of the issue easier.
>
>
> Cheers,
>
> Jeff
We was trying to find simple query, sadly unlucky. Only this query is
reproducible.

Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> The slowness was introduced with this:
> Use parameterized paths to generate inner indexscans more flexibly.

Try increasing from_collapse_limit to 11 or more.

I'm not exactly sure why the param-path patch might have changed this
behavior, but in any case the collapse limits ought to be the first
thing you think of when you see a crappy plan for a many-relation query.

The curious join nesting in this query makes me wonder if perhaps it was
hand-optimized to fit the behavior of some old version of the planner ...

regards, tom lane

On Friday, February 22, 2013, Tom Lane wrote:

> Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> > The slowness was introduced with this:
> > Use parameterized paths to generate inner indexscans more flexibly.
>
> Try increasing from_collapse_limit to 11 or more.
>

I've increased it to 20 and still no luck.

>
> I'm not exactly sure why the param-path patch might have changed this
> behavior, but in any case the collapse limits ought to be the first
> thing you think of when you see a crappy plan for a many-relation query.
>

I've stripped it down to this:

explain (analyze,buffers)
select 1 as shift_date
from cb_order order1
inner join Template template2 on order1."template" =
template2."id"
left outer join Product product1 on template2."id" =
product1."id",
Template template1 cross join Product
product2
where order1."template" = template1."id"
and (
template2."id"=product2."id"
or
case when product1."id" is not null
then 1
when template2."id" is not null
then 0
end <>1
and
product2."id"=2916353
) ;

The good plan uses a BitmapOr on a product2.id index to satisfy "
template2.id=product2.id or product2.id= 2916353" (which then needs to use
a filter to check that the CASE part holds in case the true branch of the
OR was the branch with 2916353)

The bad plan seems to have forgotten how to do that, and so seq scans
product2 repeatedly. If I remove the CASE, then it uses the BitmapOr, so
what it has forgotten seems to be that A or (B and C) can only be true if
(A or C) is true.

I say "forgot", because the planner knows that the bad plan is way worse
than the good one, so it is probably about a lack-of-proof-of-correctness
rather than some small change in cost estimation pushing one over the other.

But it isn't as simple as that, as if I replace the CASE with one that
doesn't refer to product1.id, then it relearns how to use the BitmapOr.

case when random()<0.5 then 1
when template2."id" is not null then 0
end <>1

I'm not sure where to go from here.

Cheers,

Jeff

Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> On Friday, February 22, 2013, Tom Lane wrote:
>> Try increasing from_collapse_limit to 11 or more.

> I've increased it to 20 and still no luck.

Huh --- that improved the results for me.

> I've stripped it down to this:

I'm not sure if that's exactly the same issue the OP is hitting, but
will take a look at it. Thanks for the simpler test case.

regards, tom lane