On Thu, 24 Sept 2026 at 20:21, Merlin Moncure <[email protected]> wrote:
>
> On Thu, Sep 24, 2026 at 2:39 AM vignesh C <[email protected]> wrote:
>>
>> On Wed, 23 Sept 2026 at 01:04, Merlin Moncure <[email protected]> wrote:
>>
>> > The commit solves an obvious problem, and I do not think it should be 
>> > reverted.  This does raise a couple of questions, however:
>> > * Is it really true that ereport() is up to 20x slower than stderr?
>> > * Why does stderr have such wierd performance variations?
>> > * Why does dblink even bother with NOTICE level messages at all?  They are 
>> > not produced at all to the receiving client, only to the hosting database 
>> > log (which IMO is very non-intuitive).
>> >
>> > Anecdotally, I believe I've observed much worse variations in stderr 
>> > logging in the wild, with multiple minute stall times between ~16k chunks 
>> > produced to the log.  The new behavior, while slower, does seem 
>> > consistent, which is a plus.
>>
>> Thanks for the report and the test script. I ran the script unchanged
>> on 18 and HEAD, with the server log redirected to a file using pg_ctl
>> -l.
>>                             |   18            |  HEAD
>> Loop time            |   ~34 ms.   | ~87 ms
>> Log bytes/notice. |   1,035      | 3,214
>> Log lines/notice   |   1             | 90
>>
>> So, I can reproduce the regression. In this test, it is about 2.5x
>> slower in my environment, and the log is about 3x larger.
>
>
> Excellent.  First, from a behavior standpoint, your patch gets a double 
> thumbs up;  context pollution in the logs can be a nasty problem.
>
> Applying and testing your patch, my system reverts to v18 timings, which is 
> also good. Check mark on the patch!

Thanks for verifying, here is a v2 version updating the commit message
to include Tested-by.
Now that the execution timings are ok, I feel there is no need to
update doc for this, unless you think otherwise.

> Interestingly, the v18 loop timing variances also remain:
>
> NOTICE:  LOOP: 1 00:00:00.044919
> <snip>
> NOTICE:  LOOP: 4 00:00:00.411198
> <snip>
> NOTICE:  LOOP: 6 00:00:00.960661
> NOTICE:  LOOP: 7 00:00:00.038932
> <snip>
> NOTICE:  LOOP: 10 00:00:00.964332
>
> These are obviously not related to your work.

I agree this is not related to the changes that we did in
"112faf1378ee: Log remote NOTICE, WARNING, and similar messages using
ereport()."

Regards,
Vignesh

Attachment: v2-0001-Don-t-log-local-statement-and-context-with-remote.patch
Description: Binary data

Reply via email to