Up to 50x degradation in dblink performance when receiving notice traffic 19 vs 18

From: Merlin Moncure <mmoncure(at)gmail(dot)com>
To: PostgreSQL-development <pgsql-hackers(at)postgresql(dot)org>, Fujii Masao <masao(dot)fujii(at)gmail(dot)com>, vignesh C <vignesh21(at)gmail(dot)com>
Subject: Up to 50x degradation in dblink performance when receiving notice traffic 19 vs 18
Date: 2026-09-22 19:34:06
Message-ID: CAHyXU0yDwOYkWpRi=gtpDwjBxVqeaezgkgZLRWm2p1_FgaiPFQ@mail.gmail.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

While performance testing some epoll style functionality for dblink (see
here:
https://www.postgresql.org/message-id/CAHyXU0w92SrpQtKca9dq%3DYEod44XbKWCoQuANN15C0svPLYhzw%40mail.gmail.com
if you're curious), I noticed some performance variances in stock dblink I
could not explain. The specific test involved:

1. Establish 50 dblink connections to localhost (ssl on/off doesn't matter)
2. Firing async queries through dblink_send_query across 50 connections,
where each query generated about 100k of NOTICE traffic.
3. Gather results
4. Loop to step 2, repeat 10x

PG18 behavior (showing loop timings):
NOTICE: LOOP: 1 00:00:00.037583
NOTICE: LOOP: 1 00:00:00.044958
NOTICE: LOOP: 2 00:00:00.03685
NOTICE: LOOP: 3 00:00:00.038189
NOTICE: LOOP: 4 00:00:00.378289
NOTICE: LOOP: 5 00:00:00.038016
NOTICE: LOOP: 6 00:00:00.957476
NOTICE: LOOP: 7 00:00:00.039125
NOTICE: LOOP: 8 00:00:00.926733
NOTICE: LOOP: 9 00:00:00.051012
NOTICE: LOOP: 10 00:00:00.038339

PG19 Behavior (showing loop timings)
NOTICE: LOOP: 1 00:00:02.056779
NOTICE: LOOP: 2 00:00:02.116213
NOTICE: LOOP: 3 00:00:02.10914
NOTICE: LOOP: 4 00:00:02.041574
NOTICE: LOOP: 5 00:00:02.086513
NOTICE: LOOP: 6 00:00:02.116884
NOTICE: LOOP: 7 00:00:02.184659
NOTICE: LOOP: 8 00:00:02.115044
NOTICE: LOOP: 9 00:00:02.114026
NOTICE: LOOP: 10 00:00:02.111078

Notice the time variances for pg18, it vibrates between ~ 40ms and ~1000ms
during the gather step. pg19 however, takes around 2x the worst case
behavior of pg18. Setting client_min_messages in the remote query to
WARNING is very fast in both versions.

Bisecting revealed the obvious culprit:
112faf1378ee: Log remote NOTICE, WARNING, and similar messages using
ereport().

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.

Why do we care about this? Well, it's very easy to issue dblinks that
generate a huge amount of side channel traffic, for example, by having a
large procedure that raises many notices; these sneaky context messages can
consume significant bandwidth and pad the database log. Having to adjust
client_min_messages to mitigate is a very awkward and non-obvious trick. A
note in the docs about this might be helpful IMO.

merlin

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Gustavo William 2026-09-22 19:39:58 Re: enhancing pg_basebackup speeds up to ~23Gbps (small fixes + io_uring/Direct I/O)
Previous Message Tomas Vondra 2026-09-22 19:13:52 Re: EXPLAIN: showing ReadStream / prefetch stats