Monday, May 18, 2009

Postgres 8.4 Lock Wait Statistics Tool

While working on my upcoming presentation for PGCon 2009 on Thursday, I found that sometimes it is misleading to just take one snapshot of locks to figure the hot locks in PostgreSQL workload characterization.


So again starting from one of the DTrace scripts I arrived at pglockwait_84.d


NOTE: It only works with operating systems that support DTrace. I have only tested it on OpenSolaris as of now.


It can either be used to track to summarize all PostgreSQL backends (using '*')  or selected one using process id using 10 second interval. It also prints time so that it can be dumped into a file for post-processing analysis. 


An example output  is show below during dbt-2 runs using PostgreSQL 8.4 beta1.



# ./pglockwait_84.d '*'

2009 May 19 02:52:14 Lock-Id Mode Wait-Time(ms) Count
Dynamic Locks Exclusive 0 5
ProcArrayLock Shared 0 37
Dynamic Locks Shared 1 52
CLogControlLock Exclusive 1 85
BufFreelistLock Exclusive 1 81
CLogControlLock Shared 1 103
ProcArrayLock Exclusive 2 112
BgWriterCommLock Exclusive 10 123
BufMappingLock Exclusive 11 636
XidGenLock Exclusive 17 2
BufMappingLock Shared 34 1566
WALInsertLock Exclusive 49 2305
LockMgrLock Exclusive 65 852

2009 May 19 02:52:24 Lock-Id Mode Wait-Time(ms) Count
XidGenLock Shared 0 1
XidGenLock Exclusive 0 12
ProcArrayLock Shared 1 86
BufFreelistLock Exclusive 4 240
BgWriterCommLock Exclusive 5 213
Dynamic Locks Shared 5 157
CLogControlLock Exclusive 6 238
CLogControlLock Shared 6 384
ProcArrayLock Exclusive 57 360
Dynamic Locks Exclusive 158 7
WALInsertLock Exclusive 187 7837
LockMgrLock Exclusive 226 3251
BufMappingLock Exclusive 289 2141
BufMappingLock Shared 895 5513

2009 May 19 02:52:34 Lock-Id Mode Wait-Time(ms) Count
XidGenLock Shared 0 0
Dynamic Locks Exclusive 0 6
XidGenLock Exclusive 0 5
ProcArrayLock Shared 1 76
BufFreelistLock Exclusive 3 183
BgWriterCommLock Exclusive 4 118
ProcArrayLock Exclusive 5 229
Dynamic Locks Shared 5 91
CLogControlLock Exclusive 29 198
CLogControlLock Shared 62 272
BufMappingLock Exclusive 141 1685
LockMgrLock Exclusive 206 2175
WALInsertLock Exclusive 221 5540
BufMappingLock Shared 279 4180

2009 May 19 02:52:44 Lock-Id Mode Wait-Time(ms) Count
XidGenLock Shared 0 0
Dynamic Locks Exclusive 0 3
XidGenLock Exclusive 0 5
ProcArrayLock Shared 0 67
BgWriterCommLock Exclusive 1 69
BufFreelistLock Exclusive 2 148
CLogControlLock Shared 3 262
CLogControlLock Exclusive 4 199
ProcArrayLock Exclusive 47 277
WALWriteLock Exclusive 64 2
BufMappingLock Exclusive 79 1599
WALInsertLock Exclusive 151 5949
LockMgrLock Exclusive 198 2377
BufMappingLock Shared 223 4345
Dynamic Locks Shared 1568 144
^C


It throws an output every 10 second and the time spent in acquiring the locks. For the BufMappingLock, LockMgrLock and Dynamic Locks it aggregates all of them together respectively. It's bit high on system resources if you track all Postgres backends but if you already know which one then it can be low on overhead. Hope it is useful to you too as I found it for my purpose.





No comments: