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.
--
Gregory Stark
EnterpriseDB http://www.enterprisedb.com
