Re: NOTIFY and pg_notify performance when deduplicating notifications

From: Julien Demoor <julien(at)jdemoor(dot)com>
To: Dmitry Dolgov <9erthalion6(at)gmail(dot)com>
Cc: PostgreSQL-development <pgsql-hackers(at)postgresql(dot)org>, iacobcatalin(at)gmail(dot)com
Subject: Re: NOTIFY and pg_notify performance when deduplicating notifications
Date: 2018-12-05 14:16:37
Message-ID: 60a19401-8545-08d4-8f4e-e95087e3daef@jdemoor.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Is there a particular format that is needed for the benchmark? Here's a
quick benchmark below.

Unpatched, generating N notifications takes t milliseconds:
N= 10000, t= 348
N= 20000, t=1419
N= 30000, t=3253
N= 40000, t=6170

Patched, with the 'never' collapse mode, on another (much faster) machine:
N= 10000, t= 6
N= 20000, t= 32
N= 30000, t= 11
N= 40000, t= 14
N=100000, t= 37
N=200000, t= 86

The benchmark shows that the time to send notifications grows
quadratically with the number of notifications per transaction without
the patch while it grows linearly with the patch applied and
notification collapsing disabled.

The actual psql output is below.

-- Unpatched

jdemoor=# listen my_channel;
LISTEN
Time: 0.100 ms
jdemoor=#
jdemoor=#
jdemoor=# begin;
BEGIN
Time: 0.034 ms
jdemoor=# select count(*) from (select pg_notify('my_channel', g::text)
from generate_series(1, 10000) g) x;
count
-------
10000
(1 row)

Time: 348.214 ms
jdemoor=# rollback;
ROLLBACK
Time: 0.054 ms
jdemoor=#
jdemoor=# begin;
BEGIN
Time: 0.050 ms
jdemoor=# select count(*) from (select pg_notify('my_channel', g::text)
from generate_series(1, 20000) g) x;
count
-------
20000
(1 row)

Time: 1419.723 ms (00:01.420)
jdemoor=# rollback;
ROLLBACK
Time: 0.062 ms
jdemoor=#
jdemoor=# begin;
BEGIN
Time: 0.020 ms
jdemoor=# select count(*) from (select pg_notify('my_channel', g::text)
from generate_series(1, 30000) g) x;
count
-------
30000
(1 row)

Time: 3253.845 ms (00:03.254)
jdemoor=# rollback;
ROLLBACK
Time: 0.064 ms
jdemoor=#
jdemoor=# begin;
BEGIN
Time: 0.020 ms
jdemoor=# select count(*) from (select pg_notify('my_channel', g::text)
from generate_series(1, 40000) g) x;
count
-------
40000
(1 row)

Time: 6170.646 ms (00:06.171)
jdemoor=# rollback;
ROLLBACK
Time: 0.063 ms
jdemoor=#

-- Patched

postgres=# listen my_channel;
LISTEN
Time: 0.164 ms
postgres=#
postgres=#
postgres=# begin;
BEGIN
Time: 0.099 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 10000) g) x;
count
-------
10000
(1 row)

Time: 6.092 ms
postgres=# rollback;
ROLLBACK
Time: 0.112 ms
postgres=#
postgres=# begin;
BEGIN
Time: 0.032 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 20000) g) x;
count
-------
20000
(1 row)

Time: 7.378 ms
postgres=# rollback;
ROLLBACK
Time: 0.258 ms
postgres=#
postgres=# begin;
BEGIN
Time: 0.070 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 30000) g) x;
count
-------
30000
(1 row)

Time: 11.782 ms
postgres=# rollback;
ROLLBACK
Time: 0.256 ms
postgres=#
postgres=# begin;
BEGIN
Time: 0.073 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 40000) g) x;
count
-------
40000
(1 row)

Time: 14.269 ms
postgres=# rollback;
ROLLBACK
Time: 0.144 ms
postgres=# begin;
BEGIN
Time: 0.204 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 100000) g) x;
count
--------
100000
(1 row)

Time: 37.199 ms
postgres=# rollback;
ROLLBACK
Time: 0.864 ms
postgres=#
postgres=#
postgres=# begin;
BEGIN
Time: 0.126 ms
postgres=# select count(*) from (select pg_notify('my_channel', g::text,
'never') from generate_series(1, 200000) g) x;
count
--------
200000
(1 row)

Time: 86.477 ms
postgres=# rollback;
ROLLBACK
Time: 1.292 ms

On 01/12/2018 02:35, Dmitry Dolgov wrote:
>> On Mon, Nov 19, 2018 at 8:30 AM Julien Demoor <julien(at)jdemoor(dot)com> wrote:
>>
>> Thank you for the review. I've addressed all your points in the attached
>> patch. The patch was made against release 11.1.
>
> I've noticed, that cfbot complains about this patch [1], since:
>
> Duplicate OIDs detected:
> 3423
> found 1 duplicate OID(s) in catalog data
>
> At the same time it's quite minor problem, so I'm moving it to the nexc CF
> as
> "Needs review".
>
> Also since it's performance related patch, and the latest tests I see in the
> history of this topic were posted around the time of the initial thread
> (which
> was quite some time ago), could we expect to see some new benchmarks with
> this
> patch and without? Probably the positive difference would be obvious, but
> still.
>
> [1]: https://travis-ci.org/postgresql-cfbot/postgresql/builds/461617098
>

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Oleksii Kliukin 2018-12-05 14:33:44 Re: Connection slots reserved for replication
Previous Message Pavel Stehule 2018-12-05 14:09:00 Re: proposal: plpgsql pragma statement