Re: Some interesting results from tweaking spinlocks - Mailing list pgsql-hackers

Bruce Momjian <pgman@candle.pha.pa.us> writes:
> My guess is that the lock is held for more than a few instructions, at
> least in some cases.

It is not.  LWLock and a couple of other places are the only direct uses
of spinlocks, and none of them execute more than a few lines of C code
while holding a spinlock.  Nor do they touch any wide range of memory
while doing so; your thought about cache stalls is a good one, but I
don't buy it.

I've performed some profiling on that 4-way SMP machine, and it might
be useful to look at the call patterns for LWLock, which is certainly
the main use of spinlocks.  This is an extract from gprof for one
backend process in a 25-client pgbench run, using CVS + second version
of LWLock patch:

-----------------------------------------------               0.00    0.00       1/420232      ExtendCLOG [475]
     0.00    0.00       1/420232      InitBufferPool [517]               0.00    0.00       1/420232
InitBackendSharedInvalidationState[539]               0.00    0.00       1/420232      CleanupInvalidationState [547]
           0.00    0.00       1/420232      LockMethodTableInit [511]               0.00    0.00       4/420232
GetPageWithFreeSpace[516]               0.00    0.00       8/420232      WaitIO [523]               0.00    0.00
8/420232     RecordAndGetPageWithFreeSpace [501]               0.00    0.00      10/420232      ReleaseAndReadBuffer
[513]              0.00    0.00      11/420232      XLogWrite [266]               0.00    0.00      12/420232
ShmemInitStruct[494]               0.00    0.00      14/420232      SetBufferCommitInfoNeedsSave [509]
0.00   0.00     128/420232      ProcSleep [450]               0.00    0.00     289/420232      BufferReplace [304]
        0.00    0.00     400/420232      TransactionIdSetStatus [263]               0.00    0.00     400/420232
GetNewObjectId[449]               0.00    0.00     400/420232      XLogFlush [215]               0.00    0.00
401/420232     GetNewTransactionId [448]               0.00    0.00     401/420232      CommitTransaction [47]
    0.00    0.00     403/420232      LockReleaseAll [345]               0.00    0.00     762/420232      StartBufferIO
[439]              0.00    0.00    1460/420232      TransactionIdGetStatus [192]               0.00    0.00
2000/420232     ReadNewTransactionId [388]               0.00    0.00    2000/420232      GetSnapshotData [334]
     0.00    0.00    2870/420232      WriteBuffer [346]               0.00    0.00    3204/420232      XLogInsert [43]
            0.00    0.00    9499/420232      LockRelease [107]               0.01    0.00   18827/420232
LockAcquire[66]               0.01    0.00   30871/420232      ReceiveSharedInvalidMessages [196]               0.03
0.01  76888/420232      ReleaseBuffer [80]               0.04    0.01  110970/420232      ReadBufferInternal [31]
       0.06    0.01  157987/420232      LockBuffer [55]
 
[44]     5.4    0.15    0.04  420232         LWLockAcquire [44]               0.04    0.00   29912/30040
IpcSemaphoreLock[144]               0.00    0.00    4376/7985        s_lock [596]
 


-----------------------------------------------               0.00    0.00       1/420708      InitBufferPool [517]
         0.00    0.00       1/420708      shmem_exit [554]               0.00    0.00       1/420708
InitShmemIndex[524]               0.00    0.00       1/420708      InitBackendSharedInvalidationState [539]
 0.00    0.00       1/420708      LockMethodTableInit [511]               0.00    0.00       4/420708
GetPageWithFreeSpace[516]               0.00    0.00       8/420708      WaitIO [523]               0.00    0.00
8/420708     RecordAndGetPageWithFreeSpace [501]               0.00    0.00      11/420708      ShmemInitStruct [494]
           0.00    0.00      11/420708      XLogWrite [266]               0.00    0.00      14/420708
SetBufferCommitInfoNeedsSave[509]               0.00    0.00     128/420708      ProcSleep [450]               0.00
0.00    289/420708      BufferReplace [304]               0.00    0.00     400/420708      TransactionLogUpdate [260]
           0.00    0.00     400/420708      GetNewObjectId [449]               0.00    0.00     401/420708
CommitTransaction[47]               0.00    0.00     402/420708      GetNewTransactionId [448]               0.00
0.00    403/420708      LockReleaseAll [345]               0.00    0.00     762/420708      ReadBufferInternal [31]
         0.00    0.00     762/420708      TerminateBufferIO [455]               0.00    0.00     800/420708
XLogFlush[215]               0.00    0.00    1460/420708      TransactionIdGetStatus [192]               0.00    0.00
2000/420708      ReadNewTransactionId [388]               0.00    0.00    2000/420708      GetSnapshotData [334]
      0.00    0.00    2870/420708      WriteBuffer [346]               0.00    0.00    3280/420708      XLogInsert [43]
             0.00    0.00    9499/420708      LockRelease [107]               0.00    0.00   18827/420708
LockAcquire[66]               0.01    0.00   30871/420708      ReceiveSharedInvalidMessages [196]               0.02
0.00  76888/420708      ReleaseBuffer [80]               0.02    0.00  110218/420708      BufferAlloc [42]
0.03    0.00  157987/420708      LockBuffer [55]
 
[70]     2.6    0.09    0.00  420708         LWLockRelease [70]               0.00    0.00   29982/30112
IpcSemaphoreUnlock[571]               0.00    0.00    3604/7985        s_lock [596]
 


What I draw from this is:

1. The BufMgrLock is the principal source of LWLock contention, since it
is locked more than anything else.  (The ReleaseBuffer,
ReadBufferInternal, and BufferAlloc calls are all to acquire/release
BufMgrLock.  Although LockBuffer appears to numerically exceed these
calls, the LockBuffer operations are spread out over all the per-buffer
context locks, so it's unlikely that there's much contention for any one
buffer context lock.)  It's too late in the 7.2 cycle to think about
redesigning bufmgr's interlocking but this ought to be high priority for
future work.

2. In this example, almost one in ten LWLockAcquire calls results in
blocking (calling IpcSemaphoreLock).  That seems like a lot.  I was
seeing much better results on a uniprocessor under essentially the
same test: one in a thousand LWLockAcquire calls blocked, not one in
ten.  What's causing that discrepancy?

3. The amount of spinlock-level contention seems too high too.  We
are calling s_lock about one out of every hundred LWLockAcquire or
LWLockRelease calls; the equivalent figure from a uniprocessor profile
is one in five thousand.  Given the narrow window in which the spinlock
is held, how can the contention rate be so high?

Anyone see an explanation for these last two observations?
        regards, tom lane