On Mon, 2008-02-04 at 19:46, Simon Riggs wrote:
> We've got various facilities now for looking at LWLock waits, but I'd
> like to have more information about the *reasons* for lock waits.
>
> I know its possible to get backtraces in Dtrace at various tracepoints
> but that can be fairly hard to interpret.
Simon,
A couple of guys here at Sun have started looking at trying to improve
the scaling on Sun's T2000 Niagara servers (single core, 32 HW-threads).
We mostly use various DTrace scripts to monitor locking usage. We'd be
happy to share results, probes and DTrace scripts for monitoring if you
like.
So far we've found lock contention (especially for the ProcArrayLock) to
be the likely source for our inability to saturate the CPU with a TPC-C
like OLTP load with >1000 users.
The following shows average time spent in and waiting for exclusive
ProcArrayLock vs the time used in the transaction through commit, (i.e.,
up until the exclusive ProcArrayLock acquire to update the PGPROC
setting transaction no longer running):
# ./pg-lwlock-procarray.d $(pgrep -n postgres)
postgres`LWLockAcquire
postgres`ProcArrayEndTransaction+0x10
postgres`CommitTransaction+0xf0
postgres`CommitTransactionCommand+0x90
postgres`finish_xact_command+0x60
postgres`exec_execute_message+0x3b4
postgres`PostgresMain+0x13a0
postgres`BackendRun+0x27c
postgres`BackendStartup+0xe0
postgres`ServerLoop+0x1a0
postgres`PostmasterMain+0xcbc
postgres`main+0x1d8
postgres`_start+0x108
23
avg lwlock acquire service time [ns] 193051989
transaction-commit [count] 23
transaction-start [count] 23
avg transaction time [ns] 12763079
The stack trace shows that the only time the lock is acquired
exclusively is from the call to ProcArrayEndTransaction() in
CommitTransaction().
Also, an interesting observation is that the hot locks seem to have
changed from v8.2 to v8.3, making the ProcArrayLock more contended. See
the following outputs:
PostgreSQL 8.2 (32-bit):
-bash-3.00# ./825_lwlock_wait.d
Lock Id Mode Count
FirstLockMgrLock Shared 2
ProcArrayLock Shared 209
XidGenLock Exclusive 1030
XidGenLock Shared 1215
WALInsertLock Exclusive 3942
CLogControlLock Shared 4113
ProcArrayLock Exclusive 6929
WALWriteLock Exclusive 17155
CLogControlLock Exclusive 128182
Lock Id Combined Time (ns)
FirstLockMgrLock 24705
WALInsertLock 79644210
XidGenLock 179886846
ProcArrayLock 1486950738
WALWriteLock 18425400504
CLogControlLock 1507388036453
PostgreSQL 8.3 (64-bit):
-bash-3.00# ./83_lwlock_wait.d
Lock Id Mode Count
SInvalLock Exclusive 1
WALWriteLock Exclusive 1
SInvalLock Shared 20
CLogControlLock Shared 534
CLogControlLock Exclusive 845
XidGenLock Exclusive 1140
ProcArrayLock Shared 1821
WALInsertLock Exclusive 17043
ProcArrayLock Exclusive 49762
Lock Id Mode Combined Time (ns)
SInvalLock Exclusive 17216
SInvalLock Shared 531129
WALWriteLock Exclusive 2003064
CLogControlLock Shared 61325819
CLogControlLock Exclusive 73509195
XidGenLock Exclusive 929477929
WALInsertLock Exclusive 17941476941
ProcArrayLock Shared 31114676303
ProcArrayLock Exclusive 888356047549
Regards,
Staale Smedseng
Database Technology Group, Sun Microsystems
---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend
