Re: psql 15beta1 does not print notices on the console until transaction completes - Mailing list pgsql-bugs

From Fabien COELHO
Subject Re: psql 15beta1 does not print notices on the console until transaction completes
Date
Msg-id alpine.DEB.2.22.394.2205301921520.1376708@pseudo
Whole thread Raw
In response to Re: psql 15beta1 does not print notices on the console until transaction completes  (Fabien COELHO <coelho@cri.ensmp.fr>)
Responses Re: psql 15beta1 does not print notices on the console until transaction completes
List pgsql-bugs
Hello Tom,

>>>     create or replace function test_notice() returns void as
>>>     $$
>>>     begin
>>>         raise notice 'hello';
>>>         perform pg_sleep(10);
>>>     end; $$ language plpgsql;
>> 
>>> In psql 15beta1, the "hello" message only appears on the console when the 
>>> transaction completes.
>>> in psql 14.3, it appears immediately as I would have expected.
>> 
>> A quick cross-check confirms that this is a psql, not server,
>> behavior change.  I didn't bisect, but I'm betting this is a
>> side-effect of 7844c9918 (Show all query results by default).
>
> Yep, that is indeed possible, there is some hocus-pocus around notices there 
> because they arrive somehow in any order.
>
>> I agree it's pretty undesirable, so I'm adding it as an open issue.
>
> Ok.

I've looked into it. This behavior is triggered by the fact that "psql" is 
trying to keep notices and results in some logical order.

The issue did not arise before because intermediate results where coldly 
discarded, so it did not show whether they were discarded before of after 
some notice was already shown:-)

If notices are to be shown "right away", it means that some notice may be 
shown *before* the previous result has been shown, just because psql may 
not have had time to process it and they are just sent through the 
protocol and arriving for the next result, as shown with the attached 
patch on non-regression tests:

   SELECT 1 AS one \; SELECT warn('1.5') \; SELECT 2 AS two ;
  +NOTICE:  warn 1.5
  +CONTEXT:  PL/pgSQL function warn(text) line 2 at RAISE
    one
   -----
      1
   (1 row)

  -NOTICE:  warn 1.5
  -CONTEXT:  PL/pgSQL function warn(text) line 2 at RAISE
    warn
   ------
    t

Now the second statement warning is shown before the first statement 
output. I'm pretty sure that the initial order shoul show up from time to 
time, just because of the underlying race condition.

Would this be okay? It simplifies the code significantly, but introduces 
possible race conditions in the output, which could be hidden from the non 
regression tests by removing the tests…

If notices are to be shown "right away" when processing a result, but not 
quite "right away" when the previous result is not yet finished, this is 
probably achievable but would require some effort and not so clear code. 
Maybe psql could not get the next result when we do not need to know which 
is last, but the execution would have somehow 2 different paths. I have to 
try to see how terrible or not the resulting code would be.

Another approach could be do drop the "only show the last result" 
compatibility, because then "psql" would not need to know that a result is 
the last, which requires to trigger the next one before closing the 
previous one, hence opening the race condition.

Thoughts?

-- 
Fabien.
Attachment

pgsql-bugs by date:

Previous
From: Jeff Janes
Date:
Subject: Re: BUG #17449: Disk space not released
Next
From: Andres Freund
Date:
Subject: Re: BUG #17485: Records missing from Primary Key index when doing REINDEX INDEX CONCURRENTLY