Re: LISTEN / NOTIFY performance in 8.3

At 12:43 PM -0500 2/26/08, Tom Lane wrote:
>I'm still baffled by why we aren't seeing comparable performance for the
>same test case. What I'm testing on is couple-year-old desktop kit
>(dual 2.8GHz Xeon, consumer-grade disk drive) --- I had assumed your
>server would be at least as fast as that, but maybe not?

It's a quad-core Xeon 3.0Ghz machine, 7200rpm SATA discs in a
software RAID. It's not a particularly high performance machine in
terms of disc IO - but again the comparative speed of most
select-update-commit queries to plain notify's on the server seem off.

What's really baffling is that there are plenty of other OLTP queries
going in multiple backends simultaneously that don't fall over my
300ms query log threshold, and yet NOTIFY and LISTEN consistently do.
What's more it's looks like it's only happening for registered
listener relnames.

This is while the server processes are alive but inactive:

joels=# \timing
Timing is on.
joels=# select * from pg_listener;
relname | listenerpid | notification
----------------+-------------+--------------
alert_inbound | 15013 | 0
alert_inbound | 13371 | 0
alert_inbound | 26856 | 0
alert_inbound | 12016 | 0
alert_inbound | 26911 | 0
alert_inbound | 11956 | 0
alert_process | 13365 | 0
alert_inbound | 26855 | 0
alert_inbound | 12248 | 0
alert_inbound | 13367 | 0
alert_inbound | 12304 | 0
alert_inbound | 32633 | 0
alert_inbound | 30979 | 0
alert_inbound | 29290 | 0
alert_inbound | 30394 | 0
alert_inbound | 14490 | 0
alert_inbound | 14491 | 0
alert_inbound | 14492 | 0
(18 rows)

Time: 0.402 ms
joels=# notify foo;
NOTIFY
Time: 0.244 ms
joels=# notify foo2;
NOTIFY
Time: 0.211 ms
joels=# notify alert_process;
NOTIFY
Time: 34.585 ms
joels=# notify alert_process;
NOTIFY
Time: 45.554 ms
joels=# notify alert_inbound;
NOTIFY
Time: 40.868 ms
joels=# notify alert_inbound;
NOTIFY
Time: 176.309 ms
joels=# notify alert_inbound;
NOTIFY
Time: 36.669 ms
joels=# notify alert_inbound;
NOTIFY
Time: 369.761 ms
joels=# notify alert_inbound;
NOTIFY
Time: 34.449 ms
joels=# notify alert_inbound;
NOTIFY
Time: 121.990 ms
joels=# notify foo3;
NOTIFY
Time: 0.250 ms
joels=# notify foo2;
NOTIFY
Time: 0.175 ms

There's no autovacuum log entries prior to or immediately after the
369ms notify command.

-Joel