Re[5]: LISTEN/NOTIFY ultra slow speed - Mailing list pgsql-general

From Арсен Арутюнян
Subject Re[5]: LISTEN/NOTIFY ultra slow speed
Date
Msg-id 1647542095.577013358@f474.i.mail.ru
Whole thread Raw
In response to Re[4]: LISTEN/NOTIFY ultra slow speed  (Арсен Арутюнян <arutar@bk.ru>)
List pgsql-general
I want to tell you about the problem solution. I had to move to postgres 13.
           As can be seen from the async.c code, since the 13th version, the implementation of the  LISTEN/NOTIFY mechanism has undergone major changes. The transfer of tables and database data from version 10 to version 13 went without problems.
           But there were serious difficulties with launching an application to work with the database. It turned out that since the 12th version there is no longer a pg_attrdef.adsr column and I had to patch and rebuild Qt 5.9.6.

result
 
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
 Время: 3,069 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,490 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,932 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,455 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,572 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
 Время: 2,443 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,145 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,581 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 47,704 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,631 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
 Время: 2,427 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"49064562"}');
Время: 2,647 мс
 
 
--
Arsen Arutyunyan
 
 
Вторник, 15 марта 2022, 23:48 +03:00 от Арсен Арутюнян <arutar@bk.ru>:
 
I decided to rebuild pg 10 first.
I commented out the lines of code with duplicate checking
(/src/backend/commands/async.c)
 
//    if (AsyncExistsPendingNotify(channel, payload))
//        return;
 
and launched this version of pg into production.
This was the only way I could figure out if there was a significant difference in speed. And the results turned out to be very interesting, the query speed increased  by about two times. But unfortunately it's still far from the desired level
 
before the code changes
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 974,119 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 859,855 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 695,741 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 77,001 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 475,590 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 973,449 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 1039,825 мс (00:01,040)
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 1233,576 мс (00:01,234)
 
 
after the code changes
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 431,337 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 460,794 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 498,042 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 604,931 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 438,763 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 587,827 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 621,079 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 549,264 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 447,218 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 526,980 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48119697"}');
Время: 417,556 мс
 
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 185,374 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 554,529 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 654,769 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 577,187 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
Время: 246,831 мс
rmdatabase=# select pg_notify('rmdb_client_message','{"Command":239,"MsgId":"48117898"}');
 Время: 648,865 мс
 
tomorrow I will deal with the perf
 
--
Arsen Arutyunyan
 
 
Вторник, 15 марта 2022, 17:32 +03:00 от Tom Lane <tgl@sss.pgh.pa.us>:
 
Арсен Арутюнян <arutar@bk.ru> writes:
> i looked at the file "\src\backend\commands\async.c"
> there is a check for duplicate messages

Yup.

> Is this slowdown related to this check?

[ shrug... ] You've provided no evidence either for or against that
possibility.

It seems a little unlikely that you could have a lot of pending messages
without also seeing data accumulating in pg_notify/, but on the other hand
it's also hard to think of other places that time could be getting spent
if the queue is always empty. Can you use perf(1) or some such tool to
try to identify where the time is being spent? There's some advice
about that here:

https://wiki.postgresql.org/wiki/Profiling_with_perf

> Is it possible to skip the check if I'm absolutely sure the message is unique?

Not a good idea. You could upgrade to PG 13 or later, where that
code has been improved.

regards, tom lane
 
 

pgsql-general by date:

Previous
From: "Shukla, Pranjal"
Date:
Subject: Re: Query on WAL Optimization and Streaming Replication
Next
From: Kyotaro Horiguchi
Date:
Subject: Re: PSQL bug?