Re: BUG #16967: Extremely slow update statement in trigger

Hi all,

thanks for looking into this and sorry about the dropbox link. I will
inline all further examples.

I tried running "analyze demo" after the bulk load but it does not have the
desired effect. It only works if the analyze call is executed between the
two update statements. Is it possible that the speedup in this case is a
side effect and not actually the result of the analyze call?

Here is what I tried: I reduced the number of bulk inserted records to 10k
as this still results in a significant slowdown of the update statement,
but the calls complete within 40s on my machine.

Slow run: Execute "analyze demo" after the insert and before the update
calls:
insert into demo (id, type) select i, 'blue' from generate_series(1, 10000)
s(i);
analyze demo;
update demo set type = 'black' where type='red'; -- No rows are updated and
the query executes in 2ms.
update demo set type = 'black' where type='blue'; -- Execution time: 37
seconds

Fast run: Execute "analyze demo" after the first update statement:
insert into demo (id, type) select i, 'blue' from generate_series(1, 10000)
s(i);
update demo set type = 'black' where type='red'; -- No rows are updated and
the query executes in 2ms.
analyze demo;
update demo set type = 'black' where type='blue'; -- Execution time: 51ms

Also slow run: Execute "analyze demo" after the bulk load and between the
update statements:
insert into demo (id, type) select i, 'blue' from generate_series(1, 10000)
s(i);
analyze demo;
update demo set type = 'black' where type='red'; -- No rows are updated and
the query executes in 2ms.
analyze demo;
update demo set type = 'black' where type='blue'; -- Execution time: ~37
seconds

Execution times are basically the same, whether I run all statements in one
go or if I manually execute them one by one. I even tried waiting for a
while after the "analyze demo" calls, in case there were still some
background processes running but this also had no effect on the execution
times.

Thanks again and best regards
Nicolas

Am Fr., 23. Apr. 2021 um 04:58 Uhr schrieb Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>:

> David Fetter <david(at)fetter(dot)org> writes:
> > On Fri, Apr 16, 2021 at 04:52:15PM +0000, PG Bug reporting form wrote:
> >> Bug reference: 16967
> >> Logged by: Nicolas Burri
> >> Email address: postgres(at)burri(dot)li
> >> PostgreSQL version: 13.2
> >> Operating system: Linux &amp; Windows
> >> ...
>
> > I'm including what I found on dropbox below. In future, please include
> > the entire content in emails so it stays independent of sites that
> > might not still be there when people look back.
>
> Thanks for putting that into the archives.
>
> > I did find something interesting here's the EXPLAIN for the update
> > that's intended to change everything in the table. Note that the
> > estimated rows is 1:
> > shackle(at)[local]:5414/slow_stmt_triggers(14devel)(110490) # explain
> update demo set type = 'black' where type='blue';
> > QUERY PLAN
> > ══════════════════════════════════════════════════════════════
> > Update on demo (cost=0.00..3976.35 rows=0 width=0)
> > -> Seq Scan on demo (cost=0.00..3976.35 rows=1 width=34)
> > Filter: ((type)::text = 'blue'::text)
> > (3 rows)
>
> Yeah. Of course, the plan for the UPDATE itself looks just the
> same post-ANALYZE. What we can infer is that the complex query
> within the trigger function got a really stupid plan when there
> were no stats, and then a better plan once there were some.
>
> > tl;dr: running ANALYZE after a bulk load is a good idea, and I don't
> > see a bug here.
>
> Agreed, there's little evidence here of anything but the known
> issue that auto-ANALYZE doesn't act instantaneously. If we had
> an easy way to make that better, we would, but ...
>
> regards, tom lane
>