Bug #903: Performance Hangs during Lookups

Michael Peddemors (michael(at)linuxmagic(dot)com) reports a bug with a severity of 1
The lower the number the more severe it is.

Short Description
Performance Hangs during Lookups

Long Description
We have a postgres backend to our Mail Server product, and encountering
performance issues. Simple selects are taking 7-10 seconds..
We have of course applied all the suggested performance settings for Postgres,
(We are running on Debian Stable/Linux BTW)
We moved the database to a standalone server, but still having the problems.
With app 100,000 users authenticating pop mail, plus all of the smtp
verfications, the server is expected to perform snappy queries, else mail
delivery/pickup is inordintaely long, or can't occur, and loads snowball..

We pulled some traces, and noticed, (Aside from the large amount of open()
calls, which I am not sure if we are getting IO bottlenexks from, but I
doubt) we noticed a few large gaps in time while in a semop()

Any ideas on what could be causing these large gaps in time? Note the 4.5
second gap in the strace output below.

08:51:15.069582 open("/var/postgres/global/1262", O_RDONLY) = 4
08:51:15.069822 read(4, "\0\0\0\0\fH\24\0\r\0\0\0(\0\220\36\0 \0
\354\236\270\0"
..., 8192) = 8192
08:51:19.448954 close(4) = 0
08:51:19.457810 access("/var/postgres/base/16567", F_OK) = 0
08:51:19.477631 open("/var/postgres/base/16567/PG_VERSION", O_RDONLY)
= 4
08:51:15.063311 brk(0x8213000) = 0x8213000
08:51:15.063445 old_mmap(NULL, 577536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANO
NYMOUS, -1, 0) = 0x5860d000
08:51:15.063549 brk(0x821f000) = 0x821f000
08:51:15.069582 open("/var/postgres/global/1262", O_RDONLY) = 4
08:51:15.069822 read(4, "\0\0\0\0\fH\24\0\r\0\0\0(\0\220\36\0 \0
\354\236\270\0"
..., 8192) = 8192
08:51:19.448954 close(4) = 0
08:51:19.457810 access("/var/postgres/base/16567", F_OK) = 0
08:51:19.477631 open("/var/postgres/base/16567/PG_VERSION", O_RDONLY)
= 4
08:51:19.613029 fstat64(4, {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
08:51:19.613666 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONY
MOUS, -1, 0) = 0x40014000
08:51:19.615469 read(4, "7.2\n", 4096) = 4
08:51:19.617729 close(4) = 0
08:51:19.619073 munmap(0x40014000, 4096) = 0
08:51:19.626633 chdir("/var/postgres/base/16567") = 0

Sample Code

No file was uploaded with this report