Hi, On 22/01/14 14:45, Tom Lane wrote: > Well, is it context or detail? Those fields have reasonably well defined > meanings IMO.
I find the distinction somewhat blurry and think both would be appropriate. But since I wasn't sure I changed to detail. > If we need errcontext_plural, let's add it, not adopt inferior solutions > just because that isn't there for lack of previous need. I would've added it if I would've been sure. > But having said that, I think this is indeed detail not context. > (I kinda wonder whether some of the stuff that's now in the primary > message shouldn't be pushed to errdetail as well. It looks like some > previous patches in this area have been lazy.) I agree, the primary message is not very well worded. On the other hand finding an appropriate alternative seems hard for me. > While I'm griping, this message isn't even trying to follow the project's > message style guidelines. Detail or context messages are supposed to be > complete sentence(s), with capitalization and punctuation to match. Hm, I hope I fixed it in this version of the patch. > Lastly, is this information that we want to be shipping to clients? > Perhaps from a security standpoint that's not such a wise idea, and > errdetail_log() is what should be used. Fixed. I added an errdetail_log_plural() for this, too. Best regards, -- Christian Kruse http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c index 122afb2..552c5a4 100644 --- a/src/backend/storage/lmgr/proc.c +++ b/src/backend/storage/lmgr/proc.c @@ -1195,13 +1195,23 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable) */ if (log_lock_waits && deadlock_state != DS_NOT_YET_CHECKED) { - StringInfoData buf; + StringInfoData buf, + lock_waiters_sbuf, + lock_holders_sbuf; const char *modename; long secs; int usecs; long msecs; + SHM_QUEUE *procLocks; + PROCLOCK *proclock; + bool first_holder = true, + first_waiter = true; + int lockHoldersNum = 0; initStringInfo(&buf); + initStringInfo(&lock_waiters_sbuf); + initStringInfo(&lock_holders_sbuf); + DescribeLockTag(&buf, &locallock->tag.lock); modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid, lockmode); @@ -1211,10 +1221,67 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable) msecs = secs * 1000 + usecs / 1000; usecs = usecs % 1000; + LWLockAcquire(partitionLock, LW_SHARED); + + /* + * we loop over the lock's procLocks to gather a list of all + * holders and waiters. Thus we will be able to provide more + * detailed information for lock debugging purposes. + * + * lock->procLocks contains all processes which hold or wait for + * this lock. + */ + + procLocks = &(lock->procLocks); + proclock = (PROCLOCK *) SHMQueueNext(procLocks, procLocks, + offsetof(PROCLOCK, lockLink)); + + while (proclock) + { + /* + * we are a waiter if myProc->waitProcLock == proclock; we are + * a holder if it is NULL or something different + */ + if (proclock->tag.myProc->waitProcLock == proclock) + { + if (first_waiter) + { + appendStringInfo(&lock_waiters_sbuf, "%d", + proclock->tag.myProc->pid); + first_waiter = false; + } + else + appendStringInfo(&lock_waiters_sbuf, ", %d", + proclock->tag.myProc->pid); + } + else + { + if (first_holder) + { + appendStringInfo(&lock_holders_sbuf, "%d", + proclock->tag.myProc->pid); + first_holder = false; + } + else + appendStringInfo(&lock_holders_sbuf, ", %d", + proclock->tag.myProc->pid); + + lockHoldersNum++; + } + + proclock = (PROCLOCK *) SHMQueueNext(procLocks, &proclock->lockLink, + offsetof(PROCLOCK, lockLink)); + } + + LWLockRelease(partitionLock); + if (deadlock_state == DS_SOFT_DEADLOCK) ereport(LOG, (errmsg("process %d avoided deadlock for %s on %s by rearranging queue order after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs))); + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_plural("process owning lock: %s request queue: %s", + "processes owning lock: %s request queue: %s", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); else if (deadlock_state == DS_HARD_DEADLOCK) { /* @@ -1226,13 +1293,19 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable) */ ereport(LOG, (errmsg("process %d detected deadlock while waiting for %s on %s after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs))); + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_plural("process owning lock: %s request queue: %s", + "processes owning lock: %s request queue: %s", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); } if (myWaitStatus == STATUS_WAITING) ereport(LOG, (errmsg("process %d still waiting for %s on %s after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs))); + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_plural("process owning lock: %s request queue: %s", + "processes owning lock: %s request queue: %s", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); else if (myWaitStatus == STATUS_OK) ereport(LOG, (errmsg("process %d acquired %s on %s after %ld.%03d ms", @@ -1252,7 +1325,10 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable) if (deadlock_state != DS_HARD_DEADLOCK) ereport(LOG, (errmsg("process %d failed to acquire %s on %s after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs))); + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_plural("process owning lock: %s request queue: %s", + "processes owning lock: %s request queue: %s", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); } /* @@ -1262,6 +1338,8 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable) deadlock_state = DS_NO_DEADLOCK; pfree(buf.data); + pfree(lock_holders_sbuf.data); + pfree(lock_waiters_sbuf.data); } } while (myWaitStatus == STATUS_WAITING);
pgpG4YA5SSfKr.pgp
Description: PGP signature