I think my original post here might have gotten caught in a spamtrap, so re-trying, I apologize if it ends up being a duplicate. I also forgot to mention that I'm on PG9.1.1 / RHEL 6.2 x64 I believe this is the reason for the behavior i was seeing in this post as well. http://archives.postgresql.org/pgsql-performance/2012-07/msg00035.php --- Periodically when restarting my database I find that my PREAPRE time goes through the roof. This query usually runs in a few ms total. After a recent database restart I find that it's up to 8 seconds consistantly just to PREPARE. Even EXPLAIN ends up taking time. psql -f tt.sql a Pager usage is off. Timing is on. PREPARE Time: 7965.808 ms [...] (1 row) Time: 1.147 ms I did an strace on the backend and saw the below.. it seems like there is a problem with grabbing a semaphore? strace -p 2826 Process 2826 attached - interrupt to quit semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 [snip 1000s of lines] select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) [snip 1000s of lines] semop(21069900, {{10, 1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(21069900, {{10, 1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 semop(20709441, {{5, -1, 0}}, 1) = 0 brk(0x1207000) = 0x1207000 brk(0x1229000) = 0x1229000 brk(0x124a000) = 0x124a000 mmap(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac9c6b95000 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 934, MSG_NOSIGNAL, NULL, 0) = -1 ENOTCONN (Transport endpoint is not connected) close(8) = 0 socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 8 connect(8, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 934, MSG_NOSIGNAL, NULL, 0) = 934 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 61, MSG_NOSIGNAL, NULL, 0) = 61 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 89, MSG_NOSIGNAL, NULL, 0) = 89 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 172, MSG_NOSIGNAL, NULL, 0) = 172 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 96, MSG_NOSIGNAL, NULL, 0) = 96 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 157, MSG_NOSIGNAL, NULL, 0) = 157 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 106, MSG_NOSIGNAL, NULL, 0) = 106 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 185, MSG_NOSIGNAL, NULL, 0) = 185 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 93, MSG_NOSIGNAL, NULL, 0) = 93 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 143, MSG_NOSIGNAL, NULL, 0) = 143 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 176, MSG_NOSIGNAL, NULL, 0) = 176 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 168, MSG_NOSIGNAL, NULL, 0) = 168 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 53, MSG_NOSIGNAL, NULL, 0) = 53 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 100, MSG_NOSIGNAL, NULL, 0) = 100 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 96, MSG_NOSIGNAL, NULL, 0) = 96 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 96, MSG_NOSIGNAL, NULL, 0) = 96 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 160, MSG_NOSIGNAL, NULL, 0) = 160 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 98, MSG_NOSIGNAL, NULL, 0) = 98 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 85, MSG_NOSIGNAL, NULL, 0) = 85 sendto(8, "<134>Jul 13 00:21:55 postgres[28"..., 53, MSG_NOSIGNAL, NULL, 0) = 53 sendto(7, "\2\0\0\0\300\3\0\0\3@\0\0\t\0\0\0\1\0\0\0\0\0\0\0007\n\0\0t_sc"..., 960, 0, NULL, 0) = 960 sendto(7, "\2\0\0\0\300\3\0\0\3@\0\0\t\0\0\0\0\0\0\0\0\0\0\0w\n\0\0t_sc"..., 960, 0, NULL, 0) = 960 sendto(7, "\2\0\0\0\300\3\0\0\3@\0\0\t\0\0\0\0\0\0\0\0\0\0\0009\n\0\0t_sc"..., 960, 0, NULL, 0) = 960 sendto(7, "\2\0\0\0\300\3\0\0\3@\0\0\t\0\0\0\0\0\0\0\0\0\0\0M\354\0\0t_sc"..., 960, 0, NULL, 0) = 960 sendto(7, "\2\0\0\0 \2\0\0\3@\0\0\5\0\0\0\0\0\0\0\0\0\0\0;\n\0\0t_sc"..., 544, 0, NULL, 0) = 544 sendto(7, "\2\0\0\0\350\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\275\4\0\0\0\0\0\0"..., 232, 0, NULL, 0) = 232 sendto(9, "C\0\0\0\fPREPARE\0Z\0\0\0\5I", 19, 0, NULL, 0) = 19 recvfrom(9, "Q\0\0\0\35execute x(1396, 580358);\0", 8192, 0, NULL, NULL) = 30 lseek(18, 0, SEEK_END) = 760832000 lseek(167, 0, SEEK_END) = 8192 lseek(18, 0, SEEK_END) = 760832000 lseek(167, 0, SEEK_END) = 8192 sendto(9, "T\0\0\0025\0\23col_0_0_\0\0\1\t\263\0\2\0\0\0\31\377\377\377\377\377\377"..., 805, 0, NULL, 0) = 805 recvfrom(9, "X\0\0\0\4", 8192, 0, NULL, NULL) = 5 sendto(7, "\2\0\0\0\300\3\0\0\3@\0\0\t\0\0\0\1\0\0\0\0\0\0\0007\355\0\0\0\0\0\0"..., 960, 0, NULL, 0) = 960 sendto(7, "\2\0\0\0P\1\0\0\3@\0\0\3\0\0\0\0\0\0\0\0\0\0\0\337\373\0\0\0\0\0\0"..., 336, 0, NULL, 0) = 336 exit_group(0) = ? Process 2826 detached I checked my semaphores at the os level ipcs -s|grep postgres| wc -l 54 they all look like: 0x00eb7970 21168207 postgres 600 17 0x00eb7971 21200976 postgres 600 17 0x00eb7972 21233745 postgres 600 17 0x00eb7973 21266514 postgres 600 17 0x00eb7974 21299283 postgres 600 17 0x00eb7975 21332052 postgres 600 17 0x00eb7976 21364821 postgres 600 17 When i restart the DB again things are happy: psql -f tt.sql a Pager usage is off. Timing is on. PREPARE Time: 253.850 ms [...] (1 row) Time: 0.891 ms Any ideas? Thanks -- Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
