1 SPL_Extension The Spinlock Tracing Utility (SPL) is an extension to SDA. When entered by itself with no command keyword, the SPL command lists the SPL command options. SDA> SPL You can get full help on SPL by entering HELP SPL at the SDA> prompt. 2 Overview To synchronize access to data structures, the OpenVMS operating system uses a set of static and dynamic spinlocks, such as IOLOCK8 and SCHED. The operating system acquires a spinlock to synchronize data, and at the end of the critical code path the spinlock is then released. If a CPU attempts to acquire a spinlock while another CPU is holding it, the CPU attempting to acquire the spinlock has to spin, waiting until the spinlock is released. Any lost CPU cycles within such a spinwait loop are charged as MPsynch time. By using the MONITOR utility, you can monitor the time in process modes, for example, with the command $ MONITOR MODES. A high rate of MP synchronization indicates contention for spinlocks. However, until the implementation of the Spinlock Tracing utility, there was no way to tell which spinlock was heavily used, and who was acquiring and releasing the contended spinlocks. The Spinlock Tracing utility allows a characterization of spinlock usage. It can also collect performance data for a given spinlock on a per-CPU basis. This tracing ability is built into the system synchronization execlet, which contains the spinlock code, and can be enabled or disabled while the system is running. There is no need to reboot the system to load a separate debug image. The images that provide spinlock tracing functionality are as follows: SYS$LOADABLE_IMAGES:SPL$DEBUG.EXE SYS$SHARE:SPL$SDA.EXE The SDA> prompt provides the command interface. From this command interface, you can load and unload the spinlock debug execlet using SPL LOAD and SPL UNLOAD, and start, stop and display spinlock trace data. This allows you to collect spinlock data for a given period of time without system interruption. Once information is collected, the trace buffer can be deallocated and the execlet can be unloaded to free up system resources. The spinlock trace buffer is allocated from S2 space and pages are taken from the free page list. Should the system crash while spinlock tracing is enabled, the trace buffer is dumped into the system dump file, and it can later be analyzed using the spinlock trace utility. This is very useful in tracking down CPUSPINWAIT bugcheck problems. Note that by enabling spinlock tracing, there is a performance impact. The amount of the impact depends on the amount of spinlock usage. 2 Using_SPL The following steps will enable you to collect spinlock statistics using the Spinlock Tracing Utility. 1. Load the Spinlock Tracing Utility execlet. SDA> SPL LOAD 2. Allocate a trace buffer and start tracing. SDA> SPL START TRACE 3. Wait a few seconds to allow some tracing to be done, then find out which spinlocks are incurring the most acquisitions and the most spinwaits. SDA> SPL SHOW TRACE/SUMMARY For example, you might see contention for the SCHED and IOLOCK8 spinlocks (a high acquisition count, with a significant proportion of the acquisitions being forced to wait). 4. Look to see if the spinlocks with a high proportion of spinwaits caused a significant delay in the acquisition of the spinlock. You must now collect more detailed statistics on a specific spinlock. SDA> SPL START COLLECT/SPINLOCK=SCHED This command accumulates additional data for the specified spinlock. As long as tracing is not stopped, collection will continue to accumulate spinlock-specific data from the trace buffer. 5. Display the additional data collected for the specified spinlock. SDA> SPL SHOW COLLECT This display includes the average hold time of the spinlock and the average spinwait time while acquiring the spinlock. 6. Repeat steps 4 and 5 for each spinlock that has contention. A START COLLECT cancels the previous collection. 7. Disable spinlock tracing when you have collected all the needed spinlock statistics and release all the memory used by the Spinlock Tracing utility with the following commands. SDA> SPL STOP COLLECT SDA> SPL STOP TRACE SDA> SPL UNLOAD 2 Collecting_SPL_Statistics The following example shows a command procedure that can be used for gathering spinlock statistics: $ analyze/system spl load spl start trace/buffer=1000 wait 00:00:15 spl stop trace read/executive/nolog set output spl_trace.lis spl analyze spl show trace/summary spl start collect/spin=sched wait 00:00:05 spl show collect spl start collect/spin=iolock8 wait 00:00:05 spl show collect spl start collect/spin=lckmgr wait 00:00:05 spl show collect spl start collect/spin=mmg wait 00:00:05 spl show collect spl start collect/spin=timer wait 00:00:05 spl show collect spl start collect/spin=mailbox wait 00:00:05 spl show collect spl start collect/spin=perfmon wait 00:00:05 spl show collect spl stop collect spl unload exit $ exit A more comprehensive procedure is provided as SYS$EXAMPLES:SPL.COM. 2 ANALYZE Analyzes collected spinlock data and presents the most relevant data. Format SPL ANALYZE [/[NO]CPU_STATISTICS |/[NO]PLATFORM | /[NO]HOLD_TIMES=n/[NO]WAIT_TIMES=n |/[NO]USAGE=(HOLD=n,SPIN=n,TOP_PCS=n)] 3 Qualifiers /CPU_STATISTICS /CPU_STATISTICS (default) /NOCPU_STATISTICS Displays per-CPU statistics. /HOLD_TIMES /HOLD_TIMES=n /NOHOLD_TIMES=n Displays occurrences of spinlocks held longer than n microseconds. The default is 1000 microseconds. /PLATFORM /PLATFORM (default) /NOPLATFORM Displays system platform information. /USAGE /USAGE=(HOLD=n,SPIN=n, TOP_PCS=n) Specifies thresholds for displaying information on a spinlock. If the percentage of time a spinlock is held exceeds the value of HOLD=n, where n is a value from 0 to 100, displays the information on the spinlock. The default is 10%. If the percentage of time a spinlock is spinning exceeds the value of SPIN=n, displays the information on the spinlock. The default is 10%. If either the HOLD or SPIN thresholds are exceeded, displays information on a spinlock. The TOP_PCS=n keyword displays the top n unique callers to lock a spinlock. The default is to display the top five unique callers. By specifying either /USAGE=(HOLD=0) or /USAGE=(SPIN=0), SPL displays information on all spinlock usage from the trace buffer. /WAIT_TIMES /WAIT_TIMES=n /NOWAIT_TIMES=n Displays occurrences of spinlocks held longer than n microseconds. The default is 1000 microseconds. 2 LOAD Loads the SPL$DEBUG execlet. This must be done prior to starting spinlock tracing. Format SPL LOAD 2 SHOW 3 COLLECT Displays the collected spinlock data. Format SPL SHOW COLLECT [/RATES|/TOTALS] 4 Qualifiers /RATES Reports activity as a rate per second and hold/spin time as a percentage of time. This is the default. /TOTALS Reports activity as a count and hold/spin time as cycles. 3 TRACE Displays spinlock tracing information. Format SPL SHOW TRACE [ /[NO]ACQUIRE | /CPU=n | /[NO]FORKLOCK=forklock | /[NO]FRKDSPTH | /[NO]FRKEND | /RATES | /[NO]RELEASE | /[NO]SPINLOCK=spinlock | /SUMMARY | /TOP=n | /TOTALS | /[NO]WAIT ] 4 Qualifiers /ACQUIRE /ACQUIRE /NOACQUIRE The /ACQUIRE qualifier displays any spinlock acquisitions. The /NOACQUIRE qualifier ignores any spinlock acquisitions. /CPU /CPU=n Specifies the display of information for a specific CPU only, for example, /CPU=5 or /CPU=PRIMARY. By default, all trace entries for all CPUs are displayed. /FORKLOCK /FORKLOCK=forklock /NOFORKLOCK The /FORKLOCK=forklock qualifier specifies the display of a specific forklock, for example, /FORKLOCK=IOLOCK8 or /FORKLOCK=IPL8. The /NOFORKLOCK qualifier specifies that no forklock trace information be displayed. By default, all fork trace entries are decoded and displayed. /FRKDSPTH /FRKDSPTH /NOFRKDSPTH The /FRKDSPTH qualifier displays all invocations of fork routines within the fork dispatcher. This is the default. The /NOFRKDSPTH qualifier ignores all of the operations of the /FRKDSPTH qualifier. /FRKEND /FRKEND /NOFRKEND The /FRKEND qualifier displays all returns from fork routines within the fork dispatcher. This is the default. The /NOFRKEND qualifier ignores all operations of the /FRKEND qualifier. /RATES Reports activity as a rate per second and hold/spin time as a percentage of time. This is the default. /RELEASE /RELEASE /NORELEASE The /RELEASE qualifier displays any spinlock releases. The /NORELEASE qualifier ignores any spinlock releases. /SPINLOCK /SPINLOCK=spinlock /NOSPINLOCK The /SPINLOCK=n qualifier specifies the display of a specific spinlock, for example, /SPINLOCK=LCKMGR or /SPINLOCK=SCHED. /NOSPINLOCK specifies that no spinlock trace information be displayed. By default, all spinlock trace entries are decoded and displayed. /SUMMARY Steps through the entire trace buffer and displays a summary of all spinlock and forklock activity. It also displays the top ten callers. /TOP /TOP=n Displays a different number other than the top ten callers or fork PCs. By default, the top ten are displayed. This qualifier is useful only when you also specify /SUMMARY. /TOTALS Reports activity as a count and hold/spin time as cycles. /WAIT /WAIT /NOWAIT The /WAIT qualifier displays any spinwait operations. The /NOWAIT qualifier ignores any spinwait operations. 2 START 3 COLLECT Starts to collect spinlock information a longer period of time than will fit into the trace buffer. Format SPL START COLLECT [/SPINLOCK=spinlock|/ADDRESS=n] 4 Qualifiers /ADDRESS /ADDRESS=n Specifies the tracing of a specific spinlock by address. /SPINLOCK /SPINLOCK=spinlock Specifies the tracing of a specific spinlock, for example, /SPINLOCK=LCKMGR or /SPINLOCK=SCHED. 3 TRACE Enables spinlock tracing. Format SPL START TRACE [ /[NO]ACQUIRE | /BUFFER=pages | /CPU=n | /[NO]FORKLOCK=forklock | /[NO]FRKDSPTH | /[NO]FRKEND | /[NO]RELEASE | /[NO]SPINLOCK=spinlock | /[NO]WAIT ] 4 Qualifiers /ACQUIRE /ACQUIRE /NOACQUIRE The /ACQUIRE qualifier traces any spinlock acquisitions. This is the default. The /NOACQUIRE qualifier ignores any spinlock acquisitions. /BUFFER /BUFFER=pages Specifies the size of the trace buffer (in page units). It defaults to 128 pages, which is equivalent to 1MB, if omitted. /CPU /CPU=n Specifies the tracing of a specific CPU only, for example, /CPU=5 or /CPU=PRIMARY. By default, all CPUs are traced. /FORKLOCK /FORKLOCK=forklock /NOFORKLOCK The /FORKLOCK=forklock qualifier specifies the tracing of a specific forklock, for example, /FORKLOCK=IOLOCK8 or /FORKLOCK=IPL8. The /NOFORKLOCK qualifier disables forklock tracing and does not collect any forklock data. By default, all forks are traced. /FRKDSPTH /FRKDSPTH /NOFRKDSPTH The /FRKDSPTH qualifier traces all invocations of fork routines within the fork dispatcher. This is the default. The /NOFRKDSPTH qualifier ignores all of the /FRKDSPTH operations. /FRKEND /FRKEND /NOFRKEND The /FRKEND qualifier traces all returns from fork routines within the fork dispatcher. This is the default. The /NOFRKEND qualifier ignores all of the operations of the /FRKEND qualifier. /RELEASE /RELEASE /NORELEASE The /RELEASE qualifier traces any spinlock releases. This is the default. The /NORELEASE qualifier ignores any spinlock releases. /SPINLOCK /SPINLOCK=spinlock /NOSPINLOCK The /SPINLOCK=spinlock qualifier specifies the tracing of a specific spinlock, for example, /SPINLOCK=LCKMGR or /SPINLOCK=SCHED. The /NOSPINLOCK qualifier disables spinlock tracing and does not collect any spinlock data. By default, all spinlocks are traced. /WAIT /WAIT /NOWAIT The /WAIT qualifier traces any spinwait operations. This is the default. The /NOWAIT qualifier ignores any spinwait operations. 2 STOP 3 COLLECT Stops the spinlock collection, but does not stop spinlock tracing. Format SPL STOP COLLECT 3 TRACE Disables spinlock tracing, but it does not deallocate the trace buffer. Format SPL STOP TRACE 2 UNLOAD Unloads the SPL$DEBUG execlet and performs cleanup. Tracing is automatically disabled and the trace buffer deallocated. Format SPL UNLOAD