[HACKERS] problem with locks on head, backend crash
Hello when I tested ptop, I found some problems this pgbench is very slow and when after getting table of locks from ptop I got backend crash. [EMAIL PROTECTED] ~]$ /usr/local/pgsql/bin/pgbench -c80 -t1000 postgres starting vacuum...end. WARNING: you don't own a lock of type ShareLock WARNING: you don't own a lock of type ShareLock WARNING: terminating connection because of crash of another server process DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. HINT: In a moment you should be able to reconnect to the database and repeat your command. WARNING: terminating connection because of crash of another server process DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. from log: LOG: unexpected EOF on client connection LOG: could not send data to client: Přerušena roura (SIGPIPE) LOG: unexpected EOF on client connection LOG: could not send data to client: Přerušena roura (SIGPIPE) LOG: unexpected EOF on client connection WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 LOG: server process (PID 29693) was terminated by signal 11: Segmentation fault LOG: terminating any other active server processes WARNING: terminating connection because of crash of another server process DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another s HINT: In a moment you should be able to reconnect to the database and repeat your command. WARNING: terminating connection because of crash of another server process Regards Pavel Stehule -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] problem with locks on head, backend crash
Pavel Stehule wrote: when I tested ptop, I found some problems Which version are you running? -- Heikki Linnakangas EnterpriseDB http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] problem with locks on head, backend crash
On 07/04/2008, Heikki Linnakangas [EMAIL PROTECTED] wrote: Pavel Stehule wrote: when I tested ptop, I found some problems Which version are you running? I am sorry, HEAD 8.4 today actualized Pavel -- Heikki Linnakangas EnterpriseDB http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] problem with locks on head, backend crash
Pavel Stehule escribió: WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 I suggest you make distclean and rebuild the whole thing from scratch -- I have seen these kind of problems when a loadable module is not built the same as the backend, for example. -- Alvaro Herrerahttp://www.CommandPrompt.com/ The PostgreSQL Company - Command Prompt, Inc. -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] problem with locks on head, backend crash
On 07/04/2008, Alvaro Herrera [EMAIL PROTECTED] wrote: Pavel Stehule escribió: WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 WARNING: problem in alloc set MessageContext: req size alloc size for chunk 0x8b6d1e0 in block 0x8b6bb50 I suggest you make distclean and rebuild the whole thing from scratch -- I have seen these kind of problems when a loadable module is not built the same as the backend, for example. I did it, but maybe there was some ??? I can't to repeat it after restart Pavel -- Alvaro Herrerahttp://www.CommandPrompt.com/ The PostgreSQL Company - Command Prompt, Inc. -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
[HACKERS] Problem with locks
Well the problem with spurious waits for deadlocks turned out to be quite mundane. The deadlocks were not so spurious after all... there were real deadlocks which were being hidden by a plpgsql function that caught the exception and didn't report the error. I think this is still a minor problem though. There's an asymmetry here in that log_lock_waits meant the transactions that *didn't* detect a deadlock reported log messages which couldn't be intercepted but the transactions which *did* detect a deadlock reported nothing, even though they had waited on a lock for just as long. I think we should go ahead and print a LOG message in the case where a deadlock is detected. It looks redundant since we'll also throw an error but in fact it does two things differently. a) it prints the time spent waiting before the deadlock was detected and b) it will print something even if the exception is caught ensuring that all lock waits longer than deadlock_timeout are logged similarly. I also removed the switch statement in part because I'm not certain it's actually safe to test a volatile variable in a switch expression and also because I found it confusing and unnecessary given the changes that have happened to the surrounding code since. Also, I added the process id and tried to normalize the messages to all fit the same pattern more or less. Index: src/backend/storage/lmgr/proc.c === RCS file: /home/stark/src/REPOSITORY/pgsql/src/backend/storage/lmgr/proc.c,v retrieving revision 1.191 diff -c -r1.191 proc.c *** src/backend/storage/lmgr/proc.c 16 Jul 2007 21:09:50 - 1.191 --- src/backend/storage/lmgr/proc.c 27 Aug 2007 12:45:05 - *** *** 882,936 * If awoken after the deadlock check interrupt has run, and * log_lock_waits is on, then report about the wait. */ ! if (log_lock_waits) { ! switch (deadlock_state) ! { ! case DS_NOT_YET_CHECKED: ! /* Lock granted, or spurious wakeup as described above */ ! break; ! case DS_NO_DEADLOCK: ! case DS_SOFT_DEADLOCK: ! { ! StringInfoData buf; ! const char *modename; ! long secs; ! int usecs; ! long msecs; ! ! initStringInfo(buf); ! DescribeLockTag(buf, locallock-tag.lock); ! modename = GetLockmodeName(locallock-tag.lock.locktag_lockmethodid, ! lockmode); ! TimestampDifference(timeout_start_time, ! GetCurrentTimestamp(), ! secs, usecs); ! msecs = secs * 1000 + usecs / 1000; ! usecs = usecs % 1000; ! ! if (deadlock_state == DS_SOFT_DEADLOCK) ! ereport(LOG, ! (errmsg(deadlock for %s on %s avoided by rearranging queue order after %ld.%03d ms, ! modename, buf.data, ! msecs, usecs))); ! else if (MyProc-waitStatus == STATUS_WAITING) ! ereport(LOG, ! (errmsg(process %d still waiting for %s on %s after %ld.%03d ms, ! MyProcPid, modename, buf.data, ! msecs, usecs))); ! else if (MyProc-waitStatus == STATUS_OK) ! ereport(LOG, ! (errmsg(process %d acquired %s on %s after %ld.%03d ms, ! MyProcPid, modename, buf.data, ! msecs, usecs))); ! /* ERROR will be reported later, so no message here */ ! pfree(buf.data); ! break; ! } ! case DS_HARD_DEADLOCK: ! /* ERROR will be reported later, so no message here */ ! break; ! } } } while (MyProc-waitStatus == STATUS_WAITING); --- 882,930 * If awoken after the deadlock check interrupt has run, and * log_lock_waits is on, then report about the wait. */ ! if (log_lock_waits deadlock_state != DS_NOT_YET_CHECKED) { ! StringInfoData buf; ! const char *modename; ! long secs; ! int usecs; ! long msecs; ! ! initStringInfo(buf); ! DescribeLockTag(buf, locallock-tag.lock); ! modename = GetLockmodeName(locallock-tag.lock.locktag_lockmethodid, ! lockmode); ! TimestampDifference(timeout_start_time, ! GetCurrentTimestamp(), ! secs, usecs); ! msecs = secs * 1000 + usecs / 1000; ! usecs = usecs % 1000; ! ! if (deadlock_state == DS_SOFT_DEADLOCK) ! ereport(LOG, ! (errmsg(process %d avoided deadlock waiting for %s on %s by rearranging queue order after %ld.%03d ms, ! MyProcPid, modename, buf.data, ! msecs, usecs))); ! else if (deadlock_state == DS_HARD_DEADLOCK) ! /* this is a bit redundant with the error which will be ! * reported subsequently however it adds the time elapsed and ! * it will print even if the error is caught by an exception ! * handler. */ ! ereport(LOG, ! (errmsg(process %d detected deadlock waiting for %s on %s after %ld.%03d ms, ! MyProcPid, modename, buf.data, ! msecs, usecs))); ! else if (MyProc-waitStatus == STATUS_WAITING) ! ereport(LOG, ! (errmsg(process %d still
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: I think we should go ahead and print a LOG message in the case where a deadlock is detected. That seems reasonable, but I don't find any of these other changes to be an improvement... regards, tom lane ---(end of broadcast)--- TIP 1: if posting/reading through Usenet, please send an appropriate subscribe-nomail command to [EMAIL PROTECTED] so that your message can get through to the mailing list cleanly
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: I think we should go ahead and print a LOG message in the case where a deadlock is detected. After chewing on it some more, I liked this patch better ... but I found a couple other issues, particularly with the soft-deadlock-recovery messaging sequence. Modified version committed. regards, tom lane ---(end of broadcast)--- TIP 6: explain analyze is your friend
[HACKERS] Problem with locks
I'm debugging this problem with stalled transactions waiting on locks which have already been granted and I'm puzzled by something. What is this PGPROC entry from? It's not a real process (pid is 0) and it's not garbage either (prev and next both point to a real PGPROC entry, namely MyProc which as you can see is waiting for this PGPROC). (gdb) p *(PGPROC*)(ShmemBase + MyProc-links.prev) $2 = {links = {prev = 2520941752, next = 2520941752}, sem = {semId = 1, semNum = 0}, waitStatus = 0, xid = 0, xmin = 0, pid = 0, databaseId = 0, roleId = 0, inCommit = 0 '\0', inVacuum = 0 '\0', isAutovacuum = 0 '\0', lwWaiting = 0 '\0', lwExclusive = 2 '\002', lwWaitLink = 0x0, waitLock = 0x2, waitProcLock = 0x0, waitLockMode = 0, heldLocks = 0, myProcLocks = {{prev = 0, next = 1}, { prev = 4294967296, next = 0}, {prev = 3028785127, next = 360654}, {prev = 73183493944770560, next = 137438953600}, { prev = 2520929504, next = 2520929072}, {prev = 2520940536, next = 2520940536}, {prev = 1, next = 0}, {prev = 0, next = 4294967296}, {prev = 4294967296, next = 0}, {prev = 2, next = 0}, {prev = 0, next = 0}, {prev = 1, next = 4294967296}, { prev = 0, next = 4000475635}, {prev = 360707, next = 73183493944770560}, {prev = 128, next = 2520933680}, {prev = 2520933680, next = 2520914616}}, subxids = {overflowed = -72 '�', nxids = 0, xids = {0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 1626942462, 0, 16384, 16430, 0, 16777216, 2, 0, 2520930944, 0, 2520930944, 0, 2520914784, 0, 2520914784, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 1, 0, 0, 0, 0, 0, 0, 0}}} (gdb) p MyProc-ShmemBase $3 = (PGPROC *) 0xff9ac36e36e264b8 (gdb) p (unsigned long)MyProc-ShmemBase $4 = 2520941752 -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [HACKERS] Problem with locks
Gregory Stark wrote: I'm debugging this problem with stalled transactions waiting on locks which have already been granted and I'm puzzled by something. What is this PGPROC entry from? It's not a real process (pid is 0) and it's not garbage either (prev and next both point to a real PGPROC entry, namely MyProc which as you can see is waiting for this PGPROC). Doesn't this look like your pointer arithmetic being borked? There are too many values that look invalid. (gdb) p *(PGPROC*)(ShmemBase + MyProc-links.prev) $2 = {links = {prev = 2520941752, next = 2520941752}, sem = {semId = 1, semNum = 0}, waitStatus = 0, xid = 0, xmin = 0, pid = 0, databaseId = 0, roleId = 0, inCommit = 0 '\0', inVacuum = 0 '\0', isAutovacuum = 0 '\0', lwWaiting = 0 '\0', lwExclusive = 2 '\002', lwWaitLink = 0x0, waitLock = 0x2, waitProcLock = 0x0, waitLockMode = 0, heldLocks = 0, myProcLocks = {{prev = 0, next = 1}, { prev = 4294967296, next = 0}, {prev = 3028785127, next = 360654}, {prev = 73183493944770560, next = 137438953600}, { prev = 2520929504, next = 2520929072}, {prev = 2520940536, next = 2520940536}, {prev = 1, next = 0}, {prev = 0, next = 4294967296}, {prev = 4294967296, next = 0}, {prev = 2, next = 0}, {prev = 0, next = 0}, {prev = 1, next = 4294967296}, { prev = 0, next = 4000475635}, {prev = 360707, next = 73183493944770560}, {prev = 128, next = 2520933680}, {prev = 2520933680, next = 2520914616}}, subxids = {overflowed = -72 '�', nxids = 0, xids = {0, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 0, 1626942462, 0, 16384, 16430, 0, 16777216, 2, 0, 2520930944, 0, 2520930944, 0, 2520914784, 0, 2520914784, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 1, 0, 1, 0, 0, 0, 0, 0, 0, 0}}} (gdb) p MyProc-ShmemBase $3 = (PGPROC *) 0xff9ac36e36e264b8 (gdb) p (unsigned long)MyProc-ShmemBase $4 = 2520941752 -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org -- Alvaro Herrerahttp://www.CommandPrompt.com/ PostgreSQL Replication, Consulting, Custom Development, 24x7 support ---(end of broadcast)--- TIP 9: In versions below 8.0, the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: I'm debugging this problem with stalled transactions waiting on locks which have already been granted and I'm puzzled by something. What is this PGPROC entry from? I seem to recall that there's a dummy sentinel header in proc lists ... is that what you're looking at? regards, tom lane ---(end of broadcast)--- TIP 1: if posting/reading through Usenet, please send an appropriate subscribe-nomail command to [EMAIL PROTECTED] so that your message can get through to the mailing list cleanly
Re: [HACKERS] Problem with locks
Gregory Stark wrote: I switched the code over to the sysv_sema style api. It's gotten a bit grotty and I would clean it up if it weren't a temporary test program. If we find a real problem perhaps I should add a test case like this to the smoke test in ipc_test.c so people can check their OS. So did you discover anything? I ran your test program and it worked successfully for several different configurations. Not enough times maybe, though. -- Alvaro Herrerahttp://www.CommandPrompt.com/ The PostgreSQL Company - Command Prompt, Inc. ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [HACKERS] Problem with locks
Alvaro Herrera [EMAIL PROTECTED] writes: Gregory Stark wrote: I switched the code over to the sysv_sema style api. It's gotten a bit grotty and I would clean it up if it weren't a temporary test program. If we find a real problem perhaps I should add a test case like this to the smoke test in ipc_test.c so people can check their OS. So did you discover anything? I ran your test program and it worked successfully for several different configurations. Not enough times maybe, though. I haven't been able to find any kernel problem which would explain the timeouts. The test program seems to work fine on all the machines I've tested it on except one where it turned up seemingly unrelated (and far worse) problems. But looking over the old test results from other machines I can see occasional transaction response times which exactly match the deadlock_timeout even though there should be no deadlocks. Apparently this happens with older releases of Postgres too. So I am fairly stumped here. There's really no way I can see where we would have the deadlock signal handler firing, not doing anything, but causing a semaphore wait to return. I've updated the kernel and will be running more benchmarks with the updated kernel next week. But I don't expect the results to change. -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [HACKERS] Problem with locks
Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Seems to me this proves nothing much, since it doesn't use the same SysV semaphore API PG does. I was trying to copy the semaphore API exactly assuming USE_NAMED_POSIX_SEMAPHORES was *not* defined. According to the comments we prefer not to use named semaphores if possible. What you seem to have copied is the posix_sema.c code, which AFAIK is only used on Darwin. sysv_sema.c is what to look at ... unless your benchmark machine is a Mac. I switched the code over to the sysv_sema style api. It's gotten a bit grotty and I would clean it up if it weren't a temporary test program. If we find a real problem perhaps I should add a test case like this to the smoke test in ipc_test.c so people can check their OS. I did add something like the setitimer deadlock timeout to detect a process stuck waiting. There is a race condition there if a process is woken up just as the timer fires but if the timeout is large enough the chances of that are pretty remote. Judging by the first thread the whole loop excluding the usleep takes about 3ms. I've been using a timeout of 10 seconds. As such: $ ./a.out 40 900 10 running with 40 processes for 900s with timeout of 1ms telling threads to exit run done cleaning up semaphores and shared memory #include stdlib.h #include stdio.h #include string.h #include errno.h #include unistd.h #include signal.h #include sys/types.h #include sys/ipc.h #include sys/shm.h #include sys/sem.h #include sys/time.h union semun { int val;/* Value for SETVAL */ struct semid_ds *buf;/* Buffer for IPC_STAT, IPC_SET */ unsigned short *array; /* Array for GETALL, SETALL */ struct seminfo *__buf; /* Buffer for IPC_INFO (Linux specific) */ }; #define SEMAS_PER_SET 16 #define IPCProtection (0600) /* access/modify by user only */ #define PGSemaMagic 537 /* must be less than SEMVMX */ #define SEMAS_KEY_START (5431*1000-1) int nthreads, timeout, shmid; volatile unsigned char *wakers; typedef struct PGSemaphoreData { int semId; /* semaphore set identifier */ int semNum; /* semaphore number within set */ } PGSemaphoreData; PGSemaphoreData *sems; static void atexit_handler(); static void worker(int n); static void down(int n); static void up(int n); #define MAX_THREADS 250 #define WAKER_NOOP 253 #define WAKER_EXIT 254 #define WAKER_RUNNABLE 255 /* this just forces the atexit handler to be called */ static void handle_sig(int arg) {exit(127+arg);} int main(int argc, char *argv[]) { int i, semKey, runtime; pid_t *pids; struct sigaction act, oact; int semId=-1; if (argc = 1) nthreads = 10; else nthreads = atoi(argv[1]); if (nthreads = 0 || nthreads MAX_THREADS) { fprintf(stderr, usage: nthreads not between 1 and %d\n, MAX_THREADS); exit(1); } if (argc = 2) runtime = 10; else runtime = atoi(argv[2]); if (runtime 1) { fprintf(stderr, usage: runtime shorter than 1s\n); exit(1); } if (argc = 3) timeout = 1000*60; else timeout = 1000.0*atof(argv[3]); if (timeout 1) { fprintf(stderr, usage: timeout shorter than 1s\n); exit(1); } printf(running with %d processes for %ds with timeout of %dms\n, nthreads, runtime, timeout); sems = malloc(sizeof(*sems)*nthreads); semKey = SEMAS_KEY_START; for (i=0;inthreads;i++) { union semun semun; int semNum = i % SEMAS_PER_SET; if (semNum == 0) { semKey += 1; semId = semget(semKey, SEMAS_PER_SET, IPC_CREAT | IPC_EXCL | IPCProtection); if (semId 0) { perror(semget); exit(1); } } semun.val = 0; if (semctl(semId, semNum, SETVAL, semun) 0) { fprintf(stderr, semctl(%d, %d, SETVAL, 0): %s\n, semId, semNum, strerror(errno)); exit(1); } if (semId0 || semNum SEMAS_PER_SET) exit(1); sems[i].semId = semId; sems[i].semNum= semNum; } shmid = shmget(IPC_PRIVATE, nthreads*sizeof(unsigned char), IPC_CREAT | IPC_EXCL | IPCProtection); if (shmid == -1) { perror(shmget); exit(1); } wakers = shmat(shmid, NULL, 0); wakers[0] = WAKER_NOOP; for (i=1;inthreads;i++) wakers[i] = WAKER_RUNNABLE; pids = malloc(sizeof(pid_t)*nthreads); for (i=0;inthreads;i++) { /*printf(forking thread %d\n, i);*/ switch(pids[i] = fork()) { case 0: worker(i); exit(0); case -1: perror(fork); exit(1); default: /*printf(successfully forked thread %d as pid %d\n, i, pids[i]);*/ break; } } act.sa_handler = handle_sig; sigemptyset(act.sa_mask); act.sa_flags = 0; if (sigaction(SIGINT, act, oact) 0) perror(sigaction); atexit(atexit_handler); sleep(runtime); printf(telling threads to exit\n); for (i=0;inthreads;i++) { while (wakers[i] == WAKER_RUNNABLE) { printf(still waiting for thread %d to block\n, i); sleep(1); }
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? I've written a synthetic test program to check for lost semaphore wakeups. I can't seem to produce any on my machine but haven't had a chance to run it yet on the benchmark machine that's been showing the problem. If I can't produce any lost wakeups with a program like this it looks more like it might be a Postgres or GCC bug than a Linux bug. It would be helpful if people could run this on various architectures and various versions of Linux (or other OSes). I've been running it with 40 processes for an hour, but even shorter runs would be useful. It will drive the load on your machine through the roof but doesn't cause any i/o. $ gcc -Wall ipctest.c -lrt $ ./a.out 40 3600 #include stdlib.h #include stdio.h #include semaphore.h #include unistd.h #include sys/types.h #include sys/ipc.h #include sys/shm.h #include signal.h #define IPCProtection (0600) /* access/modify by user only */ int nthreads; sem_t *sems; unsigned char *wakers; static void worker(int n); int main(int argc, char *argv[]) { int i, shmid1, shmid2, runtime; pid_t *pids; if (argc = 1) nthreads = 10; else nthreads = atoi(argv[1]); if (argc = 2) runtime = 10; else runtime = atoi(argv[2]); if (nthreads = 0 || nthreads 200) exit(1); if (runtime = 0) exit(1); printf(running with %d processes for %ds\n, nthreads, runtime); shmid1 = shmget(IPC_PRIVATE, nthreads*sizeof(sem_t), IPC_CREAT | IPC_EXCL | IPCProtection); if (shmid1 == -1) { perror(shmget:); exit(1); } sems = shmat(shmid1, NULL, 0); for (i=0;inthreads;i++) if (sem_init(sems[i], 1, 0) 0) { perror(sem_init); exit(1); } shmid2 = shmget(IPC_PRIVATE, nthreads*sizeof(unsigned char), IPC_CREAT | IPC_EXCL | IPCProtection); if (shmid2 == -1) { perror(shmget:); exit(1); } wakers = shmat(shmid2, NULL, 0); for (i=0;inthreads;i++) wakers[i] = 255; pids = malloc(sizeof(pid_t)*nthreads); for (i=0;inthreads;i++) { /*printf(forking thread %d\n, i);*/ switch(pids[i] = fork()) { case 0: worker(i); exit(0); case -1: perror(fork); exit(1); default: /*printf(successfully forked thread %d as pid %d\n, i, pids[i]);*/ break; } } sleep(runtime); kill(pids[0], 3); sleep(1); for (i=1;inthreads;i++) { if (wakers[i] == 255) printf(thread %d lost a wakeup!!!\n, i); kill(pids[i], 3); } if (shmctl(shmid1, IPC_RMID, NULL) 0) perror(smctl ipc_rmid); if (shmctl(shmid2, IPC_RMID, NULL) 0) perror(smctl ipc_rmid); exit(0); } static void worker(int n) { srandom(getpid()); for(;;) { int waker; int i; /* wake anyone following us waiting for us to wake them */ for (i=n+1;inthreads;i++) { if (wakers[i] == n) { /*printf(thread %d waking thread %d\n, n, i);*/ wakers[i] = 255; if (sem_post(sems[i]) 0) { perror(sem_post); exit(1); } } } if (n == 0) { /* we're the first thread so we just sleep and then go around waking people again */ continue; } /* otherwise pick a random thread earlier than us to wake us and go to sleep until awoken by it */ waker = random()%n; /*printf(thread %d sleeping waiting for %d to wake us\n, n, waker);*/ wakers[n] = waker; if (sem_wait(sems[n]) 0) { perror(sem_wait); exit(1); } if ((waker = wakers[n]) != 255) { printf(thread %d awake but waker is still set to %d \n, n, waker); exit(1); } /*printf(thread %d awoken\n, n);*/ } } -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [HACKERS] Problem with locks
Gregory Stark wrote: Gregory Stark [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? I've written a synthetic test program to check for lost semaphore wakeups. I can't seem to produce any on my machine but haven't had a chance to run it yet on the benchmark machine that's been showing the problem. If I can't produce any lost wakeups with a program like this it looks more like it might be a Postgres or GCC bug than a Linux bug. It would be helpful if people could run this on various architectures and various versions of Linux (or other OSes). I've been running it with 40 processes for an hour, but even shorter runs would be useful. It will drive the load on your machine through the roof but doesn't cause any i/o. doesn't work on OpenBSD: $ gcc -o ipctest ipctest.c -lpthread $ ./ipctest 40 3600 running with 40 processes for 3600s sem_init: Operation not permitted This implementation does not support shared semaphores, and reports this fact by setting errno to EPERM. This is perhaps a stretch of the intention of POSIX, but is compliant, with the caveat that sem_init() always reports a permissions error when an attempt to create a shared semaphore is made. Stefan ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [HACKERS] Problem with locks
2007/8/12, Gregory Stark [EMAIL PROTECTED]: Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? I've written a synthetic test program to check for lost semaphore wakeups. I can't seem to produce any on my machine but haven't had a chance to run it yet on the benchmark machine that's been showing the problem. If I can't produce any lost wakeups with a program like this it looks more like it might be a Postgres or GCC bug than a Linux bug. It would be helpful if people could run this on various architectures and various versions of Linux (or other OSes). I've been running it with 40 processes for an hour, but even shorter runs would be useful. It will drive the load on your machine through the roof but doesn't cause any i/o. $ gcc -Wall ipctest.c -lrt $ ./a.out 40 3600 -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq Hello [EMAIL PROTECTED] ~]$ cat /proc/sys/kernel/osrelease 2.6.22.1-41.fc7 [EMAIL PROTECTED] tmp]$ ./a.out 40 3600 running with 40 processes for 3600s [EMAIL PROTECTED] tmp]$ without any problem Regards Pavel Stehule ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: I've written a synthetic test program to check for lost semaphore wakeups. Seems to me this proves nothing much, since it doesn't use the same SysV semaphore API PG does. Please adjust so that it looks more like our code --- in particular there should be multiple processes having semaphores in the same semid group. Also, I think you have race conditions at shutdown --- the appearance of the thread %d lost a wakeup message would not convince me there was a bug in the least. You need to make sure the workers exit at a known point in their loop. regards, tom lane ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [HACKERS] Problem with locks
Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: I've written a synthetic test program to check for lost semaphore wakeups. Seems to me this proves nothing much, since it doesn't use the same SysV semaphore API PG does. Please adjust so that it looks more like our code --- in particular there should be multiple processes having semaphores in the same semid group. I was trying to copy the semaphore API exactly assuming USE_NAMED_POSIX_SEMAPHORES was *not* defined. According to the comments we prefer not to use named semaphores if possible. Also, I think you have race conditions at shutdown --- the appearance of the thread %d lost a wakeup message would not convince me there was a bug in the least. You need to make sure the workers exit at a known point in their loop. I intended to try to recreate the dynamics of the deadlock timeout timer signal. This was just a first cut. -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Seems to me this proves nothing much, since it doesn't use the same SysV semaphore API PG does. I was trying to copy the semaphore API exactly assuming USE_NAMED_POSIX_SEMAPHORES was *not* defined. According to the comments we prefer not to use named semaphores if possible. What you seem to have copied is the posix_sema.c code, which AFAIK is only used on Darwin. sysv_sema.c is what to look at ... unless your benchmark machine is a Mac. regards, tom lane ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? It does sound like it given the way my description went. I was worried it may be some code path not setting waitStatus properly or the compiler caching it incorrectly somehow. But now that I check I see it's a pretty old kernel version (Linux 2.6.5) For what it's worth we've reproduced the problem with 2.6.16.21 which is only about a year old. I want to rerun this with a shiny new 2.6.22 kernel but really 2.6.16 is recent enough that I don't know of any major bugs fixed in IPC handling since then (with the exception of hugetlb interaction which we're not using on this machine) . So now this is probably either an ongoing kernel bug affecting Postgres or it's elsewhere -- either in Postgres or GCC. I'm really concerned about this because while the behaviour with deadlock_timeout set quite high (we have it set to 60s on this machine) is bad enough -- the behaviour with it set to the default 1s is far more scary. On the default 1s timeout on a machine undergoing lock waits which are mostly under 1s you will probably never notice anything recognizably similar to this. You'll occasionally have some lock waits which last a second for no good reason but you'll never notice that. *But* if you should have a lock wait which lasts more than 1s before it's granted, then when it's granted the semaphore gets lost you're in serious doo doo. The deadlock timeout only fires once and then nothing's going to wake up that process ever again. IIRC we've actually gotten a couple reports of people claiming they've got a deadlock when there was no evidence of a deadlock in pg_locks. We always chalked it down to a single long-lived process holding the lock and blocking, but never did much analysis on those reports to see if that was really the case. It's quite possible we had users already observing this problem. If it's a real problem then we're in a bit of a bind. Even if we find and fix a Linux kernel problem we'll still have users on versions of the kernel prior to 2.6.23 or whatever has the bug fixed. We may be best off including an option to have the deadlock timer refire every deadlock_timeout interval instead of just firing once. Then we could print a message any time it occurs and include a HINT about upgrading to a kernel with the bug fixed. -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [HACKERS] Problem with locks
Tom Lane [EMAIL PROTECTED] writes: Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? It does sound like it given the way my description went. I was worried it may be some code path not setting waitStatus properly or the compiler caching it incorrectly somehow. But now that I check I see it's a pretty old kernel version (Linux 2.6.5) on the machine. The schedule was completely rewritten by Nick Piggin since then. I've suggested upgrading it but that may leave us in a bit of a pickle. If we update it then that throws away all the benchmark history since we can't really compare new benchmarks against old ones any more. -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 9: In versions below 8.0, the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
[HACKERS] Problem with locks
We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. It eventually gets the 60s deadlock signal and notices that it has been granted the lock and gets back to work. I haven't gotten any further than this in the forensic analysis and it's a bit tricky as it only happens in fairly long benchmark runs. It seems to happen every few hours of running at 3000+ transactions per minute... -- Gregory Stark EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 9: In versions below 8.0, the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [HACKERS] Problem with locks
Gregory Stark [EMAIL PROTECTED] writes: We're seeing a problem where occasionally a process appears to be granted a lock but miss its semaphore signal. Kernel bug maybe? What's the platform? regards, tom lane ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings