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.2205311331140.1672363@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
>>>>     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.

[...]

> 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…

This would be the simplest solution.

> 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.

I've tried that (see v2 attached), but it does not work as I hoped: the 
fact that a result has not yet been extracted does not preclude the server 
from sending the notices relating to a statement, so delaying the 
getResult does not fix the display order problem in anyway. I was quite 
naïve.

> 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.

That would not work, either, for the reason stated above.

In order to have the best of both world, this requires more hopus-pocus: 
accumulating the notices *but* displaying them as soon as dealing with a 
statement is done *and* also while waiting for getResult. I see how I can 
try to reduce a lot the out-of-order window… but not how to fully get rid 
of it.

-- 
Fabien.
Attachment

pgsql-bugs by date:

Previous
From: Gregory Jensen
Date:
Subject: Inconsistent time zone output for JSON at UTC
Next
From: "David G. Johnston"
Date:
Subject: Re: Inconsistent time zone output for JSON at UTC