Logging Lock Waits
Right now, I need a way to log the lock wait times for certain queries,
to see if they are acceptable. DTrace is not available.
I'm dealing with a problem that is either a standard lock wait involving
RI trigger locking, or a weirder problem involving lock starvation as a
result of soft deadlock queue re-arrangement. I doubt its the latter but
neither situation can be straightforwardly enabled to diagnose the
situation.
Sometime earlier, I proposed log_min_lockwait.
A frequent case is where the lockwait is so long that the statement
effectively never completes, so the statement duration doesn't appear in
the log. That can cause further diagnosis problems.
Ideally, I'd like to know both
1. there is a lock wait and it is happening now
2. there was a lock wait and it was THIS bad
For 1, I need to log something while the lock wait is happening, not
just when it ends - it might not end successfully. For 2 we can log it
during or afterwards, not a problem.
I'm thinking to write an INFO message, so that people can choose to log
this and/or the SQL statement if they choose.
e.g. INFO: lock wait time of XXX secs has been exceeded
Comments?
--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com
"Simon Riggs" <simon@2ndquadrant.com> writes:
I'm thinking to write an INFO message, so that people can choose to log
this and/or the SQL statement if they choose.
e.g. INFO: lock wait time of XXX secs has been exceeded
The available timer resources are already overloaded; adding an
independent timeout for this will complicate the code more than seems
justified. Perhaps you could add a LOG message whenever the
deadlock-check code runs (and doesn't detect an error, so is about to go
back to sleep). This would take almost no effort, and the granularity
could still be adjusted via the deadlock check timeout.
regards, tom lane
On Jan 30, 2007, at 6:32 PM, Tom Lane wrote:
"Simon Riggs" <simon@2ndquadrant.com> writes:
I'm thinking to write an INFO message, so that people can choose
to log
this and/or the SQL statement if they choose.
e.g. INFO: lock wait time of XXX secs has been exceededThe available timer resources are already overloaded; adding an
independent timeout for this will complicate the code more than seems
justified. Perhaps you could add a LOG message whenever the
deadlock-check code runs (and doesn't detect an error, so is about
to go
back to sleep). This would take almost no effort, and the granularity
could still be adjusted via the deadlock check timeout.
Sybase collected performance information for a server by periodically
checking the status of all backend processes (ie: waiting on a user
lock, waiting on IO, internal lock, etc) and keeping counters. Having
that information available was useful for debugging performance
issues (unfortunately I can't provide any specific examples since it
was years ago I played with it). I'm thinking backends could set
flags in shared memory to indicate what they're doing and a process
could poll that every X milliseconds and keep stats on what's going on.
But maybe that's more along the lines of the rewrite of the stats
system that's been talked about...
--
Jim Nasby jim@nasby.net
EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)