Re[4]: LISTEN/NOTIFY ultra slow speed

From: Арсен Арутюнян <arutar(at)bk(dot)ru>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: pgsql-general <pgsql-general(at)postgresql(dot)org>
Subject: Re[4]: LISTEN/NOTIFY ultra slow speed
Date: 2022-03-15 20:48:42
Message-ID: 1647377322.779959664@f422.i.mail.ru
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general


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(at)sss(dot)pgh(dot)pa(dot)us>:

>=?UTF-8?B?0JDRgNGB0LXQvSDQkNGA0YPRgtGO0L3Rj9C9?= < arutar(at)bk(dot)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
 

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Shaozhong SHI 2022-03-16 20:14:43 Apparently table locks are the key issue to see red flags
Previous Message Adrian Klaver 2022-03-15 17:40:49 Re: [External]Re: Postgres Crash Issue