Обсуждение: Adding nextval() to a select caused hang/very slow execution

Eric Raskin <eraskin@paslists.com> writes:
> I have a strange situation where a base query completes in about 30 seconds
> but if I add a nextval() call to the select it never completes.  There are
> other processes running that are accessing the same sequence, but I thought
> that concurrency was not an issue for sequences (other than skipped
> values).

Shouldn't be, probably ... but did you check to see if the query is
blocked on a lock?  (See pg_stat_activity or pg_locks views.)

> The only change that
> causes it to be extremely slow or hang (can't tell which) is that I changed
> the select from:
> select unnest(....
> to
> select nextval('sbowner.idgen'), unnest(....

Without seeing the complete query it's hard to say much.  But if
this isn't the topmost select list, maybe what's happening is that
the presence of a volatile function in a sub-select is defeating
some key plan optimization.  Did you compare plain EXPLAIN (w/out
ANALYZE) output for the two cases, to see if the plan shape changes?

                        regards, tom lane

Thanks for the reply.  I see that the explain.depesz.com did not show you the query.  My apologies:

select unnest(array[273941676,273941677,273941678,273941679,273941680]) countrow_id, 

       disporder, fmtdate, typecode, 

       unnest(array[count_273941676,count_273941677,count_273941678,count_273941679,count_273941680]) countval

 from (select coalesce(count(distinct id_273941676),0) count_273941676, 

              coalesce(count(distinct id_273941677),0) count_273941677, 

              coalesce(count(distinct id_273941678),0) count_273941678, 

              coalesce(count(distinct id_273941679),0) count_273941679, 

              coalesce(count(distinct id_273941680),0) count_273941680, 

                         disporder, fmtdate, typecode 

        from (select case when sexcode = 'M' then id else null end id_273941676,

                     case when sexcode = 'F' then id else null end id_273941677, 

                     case when sexcode = 'A' then id else null end id_273941678, 

                     case when sexcode = 'C' then id else null end id_273941679, 

                     case when sexcode not in ('M','F','A','C') then id else null end id_273941680, 

                     hotline cnt_hotline 

               from lruser.fortherb_indcounts c 

               where ( (rtype = '2') 

                and ((sexcode = 'M') or (sexcode = 'F') or (sexcode = 'A') or (sexcode = 'C') or (sexcode not in ('M','F','A','C'))

               )

            )

      ) as x

right outer join count_tempcols t on (x.cnt_hotline between t.mindate and t.maxdate) group by disporder, fmtdate, typecode ) as y

I know it seems overly complicated, but it is auto-generated by our code.  The conditions and fields are variable based on what the user wants to generate.  

This is the topmost select.  The only difference that causes the hang is adding nextval('sbowner.idgen') to the start of the select right before the first unnest().

In the real application, this code feeds an insert statement with a trigger that accesses the sequence where we store the results of the query.  I "simplified" it and discovered that the nextval() was the difference that caused the performance hit.

   Eric

On Wed, Nov 4, 2020 at 1:04 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:

Eric Raskin <eraskin@paslists.com> writes:
> I have a strange situation where a base query completes in about 30 seconds
> but if I add a nextval() call to the select it never completes.  There are
> other processes running that are accessing the same sequence, but I thought
> that concurrency was not an issue for sequences (other than skipped
> values).

Shouldn't be, probably ... but did you check to see if the query is
blocked on a lock?  (See pg_stat_activity or pg_locks views.)

> The only change that
> causes it to be extremely slow or hang (can't tell which) is that I changed
> the select from:
> select unnest(....
> to
> select nextval('sbowner.idgen'), unnest(....

Without seeing the complete query it's hard to say much.  But if
this isn't the topmost select list, maybe what's happening is that
the presence of a volatile function in a sub-select is defeating
some key plan optimization.  Did you compare plain EXPLAIN (w/out
ANALYZE) output for the two cases, to see if the plan shape changes?

                        regards, tom lane

--

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Eric H. Raskin                                                                                                      914-765-0500 x120 or 315-338-4461 (direct)

Professional Advertising Systems Inc.                                                                     fax: 914-765-0500 or 315-338-4461 (direct)

3 Morgan Drive #310                                                                                           eraskin@paslists.com

Mt Kisco, NY 10549                                                                                              http://www.paslists.com

Eric Raskin <eraskin@paslists.com> writes:
> And, to follow up on your question, the plan shape DOES change when I
> add/remove the nextval() on a plain explain.
> Without nextval():  https://explain.depesz.com/s/SCdY
> With nextval():  https://explain.depesz.com/s/oLPn

Ah, there's your problem, I think: the plan without nextval() is
parallelized while the plan with nextval() is not, because nextval() is
marked as parallel-unsafe.  It's not immediately clear why that would
result in more than about a 4X speed difference, given that the parallel
plan is using 4 workers.  But some of the rowcount estimates seem fairly
far off, so I'm betting that the planner is just accidentally lighting on
a decent plan when it's using parallelism while making some poor choices
when it isn't.

The reason for the original form of your problem is likely that we don't
use parallelism at all in non-SELECT queries, so you ended up with a bad
plan even though the nextval() was hidden in a trigger.

What you need to do is get the rowcount estimates nearer to reality
--- those places where you've got estimated rowcount 1 while reality
is tens or hundreds of thousands of rows are just disasters waiting
to bite.  I suspect most of the problem is join conditions like

Join Filter: (CASE WHEN (c.rtype = ANY ('{0,1,7,9}'::bpchar[])) THEN c.rtype ELSE x.rtype END = '2'::bpchar)

The planner just isn't going to have any credible idea how selective
that is.  I wonder to what extent you could fix this by storing
generated columns that represent the derived conditions you want to
filter on.

                        regards, tom lane

Eric Raskin <eraskin@paslists.com> writes:
> And, of course, your explanation that inserts will not be parallelized must
> be the reason.  I will certainly re-vacuum the tables.  I wonder why
> auto-vacuum didn't collect better stats.  vacuum  analyze <table> is all I
> need, right?

Plain ANALYZE is enough to collect stats; but I doubt that'll improve
matters for you.  The problem is basically that the planner can't do
anything with a CASE construct, so you end up with default selectivity
estimates for anything involving a CASE, statistics or no statistics.
You need to try to reformulate the query with simpler join conditions.

> As a last resort, what about a PL/PGSQL procedure loop on the query
> result?  Since the insert is very few rows relative to the work the select
> has to do, I could just turn the insert.. select.. into a for loop.  Then
> the select could be parallel?

Maybe, but you're still skating on a cliff edge.  I think it's pure chance
that the parallelized query is working acceptably well; next month with
slightly different conditions, it might not.

                        regards, tom lane

On Wed, Nov 4, 2020 at 12:12 PM Eric Raskin <eraskin@paslists.com> wrote:

OK - I see.  And to add insult to injury, I tried creating a temporary table to store the intermediate results.  Then I was going to just do an insert... select... to insert the rows.   That would de-couple the nextval() from the query.

Strangely, the first query I tried it on worked great.  But, when I tried to add a second set of data with a similar query to the same temporary table, it slowed right down again.  And, of course, when I remove the insert, it's fine. 

I am not entirely sure I am understanding your process properly, but just a note- If you are getting acceptable results creating the temp table, and the issue is just that you get very bad plans when using it in some query that follows, then it is worth noting that autovacuum does nothing on temp tables and for me it is nearly always worth the small cost to perform an analyze (at least on key fields) after creating a temp table, or rather after inserting/updating/deleting records in a significant way.