On Thu, 2007-07-26 at 17:17 -0400, Jignesh K. Shah wrote:
> Lock Id Combined Time (ns)
> XidGenLock 194966200
> WALInsertLock 517955000
> CLogControlLock 679665100
> WALWriteLock 2838716200
> ProcArrayLock 44181002600
Is this the time the lock is held for or the time that we wait for that
lock? It would be good to see the break down of time separately for
shared and exclusive.
Can we have a table like this:
LockId,LockMode,SumTimeLockHeld,SumTimeLockWait
> Top Wait time seems to come from the following code path for
> ProcArrayLock:
>
> Lock Id Mode Count
> ProcArrayLock Exclusive 21
>
> Lock Id Combined Time (ns)
> ProcArrayLock 5255937500
>
> Lock Id Combined Time (ns)
>
>
> postgres`LWLockAcquire+0x1f0
> postgres`CommitTransaction+0x104
> postgres`CommitTransactionCommand+0xbc
> postgres`finish_xact_command+0x78
Well thats pretty weird. That code path clearly only happens once per
transaction and ought to be fast. The other code paths that take
ProcArrayLock like TransactionIdIsInProgress() and GetSnapshotData()
ought to spend more time holding the lock. Presumably you are running
with a fair number of SERIALIZABLE transactions?
Are you running with commit_delay > 0? Its possible that the call to
CountActiveBackends() is causing pinging of the procarray by other
backends while we're trying to read it during CommitTransaction(). If
so, try the attached patch.
--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com
