MIME-Version: 1.0
References: <CAGSzHa0WS6pQM6fvrC1Uq74AON9sZgZj0LOkDe=_yrsVMfcx=w@mail.gmail.com>
In-Reply-To: <CAGSzHa0WS6pQM6fvrC1Uq74AON9sZgZj0LOkDe=_yrsVMfcx=w@mail.gmail.com>
From: =?UTF-8?Q?Torsten_F=C3=B6rtsch?= <tfoertsch123@gmail.com>
Date: Tue, 30 Apr 2024 12:57:43 +0200
Message-ID: <CAKkG4_n6p2gk4TL74ooO3o57xM-o-GfcuPMd7N9vx4QS=8-qKA@mail.gmail.com>
Subject: Re: pg_notify contention
To: Dimitris Zenios <dimitris.zenios@gmail.com>
Cc: pgsql-general@lists.postgresql.org
Content-Type: multipart/alternative; boundary="000000000000f0bc5a06174e3ddd"
Archived-At: <https://www.postgresql.org/message-id/CAKkG4_n6p2gk4TL74ooO3o57xM-o-GfcuPMd7N9vx4QS%3D8-qKA%40mail.gmail.com>
Precedence: bulk

--000000000000f0bc5a06174e3ddd
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

As part of the commit operation, Postgres inserts the notification into a
queue. Naturally, that insert is guarded by a lock and that lock is
released only at the very end of the commit operation. This effect gets
much worse if you also configure synchronous replication because commit
finishes only when the desired sync level has been achieved.

An alternative solution could be to receive notification through the WAL
stream. Use pg_revclogical to connect to a replication slot configured with
wal2json. Then you can send notifications with pg_logical_emit_message()
for instance which even allows you to send notifications from aborted
transactions.

Setup:
SELECT * FROM pg_create_logical_replication_slot('w2j', 'wal2json');

Here is a sender:
CREATE SCHEMA notify;
CREATE OR REPLACE FUNCTION notify.send(
    transactional BOOLEAN,
    channel TEXT,
    message TEXT
) RETURNS PG_LSN AS $$
    SELECT pg_logical_emit_message(
               transactional,
               'NOTIFY_'||channel,
               jsonb_build_object(
                   'txn_start', now()::TEXT,
                   'pid', pg_backend_pid(),
                   'message', message
               )::TEXT
           );
$$ LANGUAGE sql VOLATILE;

And something like this as a receiver / distributor:
sudo -iu postgres /usr/lib/postgresql/$VERSION/bin/pg_recvlogical \
     -d 'port=3D5432 dbname=3Dyour_database' \
     -S w2j \
     -f - \
     -F 0 \
     --start \
     -o include-xids=3D1 \
     -o include-timestamp=3D1 \
     -o add-tables=3Dnotify.\* \
     -o format-version=3D2 |
jq 'select(.action=3D=3D"M" and (.prefix | test("^NOTIFY_"))) |
    . as $x |
    .content |
    fromjson + {
        "channel": ($x.prefix | .[7:]),
        "xid": $x.xid,
        "txn_commit": $x.timestamp,
        "transactional": $x.transactional
    }'

Note, this is not a 100% replacement. The semantics are slightly different.
You also need a replication slot which comes with its own maintenance cost.
But maybe it's worth a try.

Have fun,
Torsten

On Tue, Apr 30, 2024 at 12:05=E2=80=AFPM Dimitris Zenios <dimitris.zenios@g=
mail.com>
wrote:

> Hi,
>
> I am measuring a very simple case of pg_notify in an after update trigger=
.
> The trigger is the following:
>
> CREATE
>     OR REPLACE FUNCTION audit_event() RETURNS TRIGGER AS
> $$
> BEGIN
>     PERFORM pg_notify('user', 'hello world');
>     RETURN NULL;
> END;
> $$
>     LANGUAGE plpgsql;
>
> and configured on the table with the following sql
>
> CREATE CONSTRAINT TRIGGER trigger_test AFTER UPDATE ON pgbench_accounts
> FOR EACH ROW EXECUTE PROCEDURE audit_event()
>
> I am running two benchmarks. One with the pg_notify on the trigger enable=
d
> and one with the notify commented out.
>
> The command is the following:
> pgbench -f /tmp/update_bench.sql  -c 10 -j 10 -t 100 benchdb
>
> And the content of the update_bench.sql are the following
>
> \set aid random(1, 100000 * :scale)
> \set delta random(-5000, 5000)
> BEGIN;
> UPDATE pgbench_accounts SET abalance =3D abalance + :delta WHERE aid =3D =
:aid;
> END;
>
> Results are
>
> - With pg_notify disabled
>
> pgbench (16.1)
> starting vacuum...end.
> transaction type: /tmp/update_bench.sql
> scaling factor: 1
> query mode: simple
> number of clients: 10
> number of threads: 10
> maximum number of tries: 1
> number of transactions per client: 100
> number of transactions actually processed: 1000/1000
> number of failed transactions: 0 (0.000%)
> latency average =3D 11.744 ms
> initial connection time =3D 15.616 ms
> tps =3D 851.531991 (without initial connection time)
>
> - With pg_notify enabled
>
> pgbench (16.1)
> starting vacuum...end.
> transaction type: /tmp/update_bench.sql
> scaling factor: 1
> query mode: simple
> number of clients: 10
> number of threads: 10
> maximum number of tries: 1
> number of transactions per client: 100
> number of transactions actually processed: 1000/1000
> number of failed transactions: 0 (0.000%)
> latency average =3D 56.927 ms
> initial connection time =3D 11.182 ms
> tps =3D 175.664989 (without initial connection time)
>
> There is a huge drop in TPS from 851 to 175.
>
> I also noticed that if I run the test with a single connection -c 1 then
> the results are nearly identical which makes me assume that this is a
> contention that occurs between multiple connections.
>
> Thanks
>
>

--000000000000f0bc5a06174e3ddd
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">As part of the commit operation, Postgres inserts the noti=
fication into a queue. Naturally, that insert is guarded by a lock and that=
 lock is released only at the very end of the commit operation. This effect=
 gets much worse if you also configure synchronous replication because comm=
it finishes only when the desired sync level has been achieved.<div><br></d=
iv><div>An alternative solution could be to receive notification through th=
e WAL stream. Use pg_revclogical to connect to a replication slot configure=
d with wal2json. Then you can send notifications with=C2=A0pg_logical_emit_=
message() for instance which even allows you to send notifications from abo=
rted transactions.</div><div><br></div><div>Setup:</div><div>SELECT * FROM =
pg_create_logical_replication_slot(&#39;w2j&#39;, &#39;wal2json&#39;);<br><=
/div><div><br></div><div>Here is a sender:</div><div>CREATE SCHEMA notify;<=
br>CREATE OR REPLACE FUNCTION notify.send(<br>=C2=A0 =C2=A0 transactional B=
OOLEAN,<br>=C2=A0 =C2=A0 channel TEXT,<br>=C2=A0 =C2=A0 message TEXT<br>) R=
ETURNS PG_LSN AS $$<br>=C2=A0 =C2=A0 SELECT pg_logical_emit_message(<br>=C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0transactional,<br>=C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0&#39;NOTIFY_&#39;||chan=
nel,<br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0jsonb_build_=
object(<br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0&#39;txn_start&#39;, now()::TEXT,<br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0&#39;pid&#39;, pg_backend_pid(),<br>=
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0&#39;m=
essage&#39;, message<br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0)::TEXT<br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0);<br>$$ LANGUAGE=
 sql VOLATILE;<br></div><div><br></div><div>And something like this as a re=
ceiver / distributor:</div><div>sudo -iu postgres /usr/lib/postgresql/$VERS=
ION/bin/pg_recvlogical \<br>=C2=A0 =C2=A0 =C2=A0-d &#39;port=3D5432 dbname=
=3Dyour_database&#39; \<br>=C2=A0 =C2=A0 =C2=A0-S w2j \<br>=C2=A0 =C2=A0 =
=C2=A0-f - \<br>=C2=A0 =C2=A0 =C2=A0-F 0 \<br>=C2=A0 =C2=A0 =C2=A0--start \=
<br>=C2=A0 =C2=A0 =C2=A0-o include-xids=3D1 \<br>=C2=A0 =C2=A0 =C2=A0-o inc=
lude-timestamp=3D1 \<br>=C2=A0 =C2=A0 =C2=A0-o add-tables=3Dnotify.\* \<br>=
=C2=A0 =C2=A0 =C2=A0-o format-version=3D2 |<br>jq &#39;select(.action=3D=3D=
&quot;M&quot; and (.prefix | test(&quot;^NOTIFY_&quot;))) |<br>=C2=A0 =C2=
=A0 . as $x |<br>=C2=A0 =C2=A0 .content |<br>=C2=A0 =C2=A0 fromjson + {<br>=
=C2=A0 =C2=A0 =C2=A0 =C2=A0 &quot;channel&quot;: ($x.prefix | .[7:]),<br>=
=C2=A0 =C2=A0 =C2=A0 =C2=A0 &quot;xid&quot;: $x.xid,<br>=C2=A0 =C2=A0 =C2=
=A0 =C2=A0 &quot;txn_commit&quot;: $x.timestamp,<br>=C2=A0 =C2=A0 =C2=A0 =
=C2=A0 &quot;transactional&quot;: $x.transactional<br>=C2=A0 =C2=A0 }&#39;<=
br></div><div><br></div><div>Note, this is not a 100% replacement. The sema=
ntics are slightly different. You also need a replication slot which comes =
with its own maintenance cost. But maybe it&#39;s worth a try.</div><div><b=
r></div><div>Have fun,</div><div>Torsten</div></div><br><div class=3D"gmail=
_quote"><div dir=3D"ltr" class=3D"gmail_attr">On Tue, Apr 30, 2024 at 12:05=
=E2=80=AFPM Dimitris Zenios &lt;<a href=3D"mailto:dimitris.zenios@gmail.com=
">dimitris.zenios@gmail.com</a>&gt; wrote:<br></div><blockquote class=3D"gm=
ail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,=
204,204);padding-left:1ex"><div dir=3D"ltr">Hi,=C2=A0<div><br></div><div>I =
am measuring a very simple case of pg_notify in an after update trigger. Th=
e trigger is the following:<br><br>CREATE<br>=C2=A0 =C2=A0 OR REPLACE FUNCT=
ION audit_event() RETURNS TRIGGER AS<br>$$<br>BEGIN<br>=C2=A0 =C2=A0 PERFOR=
M pg_notify(&#39;user&#39;, &#39;hello world&#39;);<br>=C2=A0 =C2=A0 RETURN=
 NULL;<br>END;<br>$$<br>=C2=A0 =C2=A0 LANGUAGE plpgsql;</div><div><br></div=
><div>and configured on the table with the following sql</div><div><br></di=
v><div>CREATE CONSTRAINT TRIGGER trigger_test AFTER UPDATE ON pgbench_accou=
nts FOR EACH ROW EXECUTE PROCEDURE audit_event()<br><br>I am running two be=
nchmarks. One with the pg_notify on the trigger enabled and one with the no=
tify commented out.<br><br>The command is the following:<div>pgbench -f /tm=
p/update_bench.sql =C2=A0-c 10 -j 10 -t 100 benchdb<br><br>And the content =
of the update_bench.sql are the following</div><div><br></div><div>\set aid=
 random(1, 100000 * :scale)<br>\set delta random(-5000, 5000)<br>BEGIN;<br>=
UPDATE pgbench_accounts SET abalance =3D abalance + :delta WHERE aid =3D :a=
id;<br>END;<br><div><br></div><div>Results are</div><div><br></div><div>- W=
ith pg_notify disabled</div><div><br></div><div>pgbench (16.1)<br>starting =
vacuum...end.<br>transaction type: /tmp/update_bench.sql<br>scaling factor:=
 1<br>query mode: simple<br>number of clients: 10<br>number of threads: 10<=
br>maximum number of tries: 1<br>number of transactions per client: 100<br>=
number of transactions actually processed: 1000/1000<br>number of failed tr=
ansactions: 0 (0.000%)<br>latency average =3D 11.744 ms<br>initial connecti=
on time =3D 15.616 ms<br>tps =3D 851.531991 (without initial connection tim=
e)<br></div><div><br></div><div>- With pg_notify enabled</div><div><br></di=
v><div>pgbench (16.1)<br>starting vacuum...end.<br>transaction type: /tmp/u=
pdate_bench.sql<br>scaling factor: 1<br>query mode: simple<br>number of cli=
ents: 10<br>number of threads: 10<br>maximum number of tries: 1<br>number o=
f transactions per client: 100<br>number of transactions actually processed=
: 1000/1000<br>number of failed transactions: 0 (0.000%)<br>latency average=
 =3D 56.927 ms<br>initial connection time =3D 11.182 ms<br>tps =3D 175.6649=
89 (without initial connection time)<br></div><div><br></div><div>There is =
a huge drop in TPS from 851 to 175.</div><div><br></div><div>I also noticed=
 that if I run the test with a single connection -c 1 then the results are =
nearly identical which makes me assume that this is a contention that occur=
s between multiple connections.</div><div><br></div><div>Thanks</div><div><=
br></div></div></div></div>
</blockquote></div>

--000000000000f0bc5a06174e3ddd--