hp.com home products and services support and drivers solutions how to buy
cd-rom home
End of Jump to page title
HP OpenVMS systems
documentation

Jump to content


HP OpenVMS System Analysis Tools Manual

HP OpenVMS System Analysis Tools Manual


Previous Contents Index


OCLA STOP

Stops the acquisition of instructions.

Format

OCLA STOP [/CPU=n]


Parameters

None.

Qualifier

/CPU=n

Specifies the CPU on which to stop acquisition. If this qualifier is omitted, acquisition is stopped on all CPUs.

Description

Stops the acquisition of instructions.

OCLA UNLOAD

Unloads the OCLA$PCTRACE execlet and returns the acquisition buffers to the system.

Format

OCLA UNLOAD


Parameters

None.

Qualifiers

None.

Description

Unloads the OCLA$PCTRACE execlet and returns the acquisition buffers to the system.


Chapter 7
SDA Alignment Fault Utility (FLT)

The Alignment Fault Utility can be used to find alignment faults.

7.1 Overview of FLT

The utility can be started and stopped as required without the need for a system reboot. It records all alignment faults into a ring buffer, which can be sized when starting alignment fault tracing. The summary screen displays the results sorted by the program counter (PC) that has incurred the most alignment faults. The detailed trace output also shows the process identification (PID) of the process that caused the alignment fault, with the virtual address that triggered the fault.

Output can be directed to a file with the SDA SET OUTPUT command.

7.2 FLT Commands

To use the FLT utility, several commands and qualifiers are available. Table 7-1 describes these commands and qualifiers.

Table 7-1 Commands for the Alignment Fault Utility
Commands Description
FLT LOAD Loads the FLT$DEBUG execlet.
FLT UNLOAD Unloads the FLT$DEBUG execlet.
FLT START TRACE Starts alignment fault tracing.

[/BUFFER=pages] - the number of pages to size the trace buffer (default = 128 pages = 1MB).

[/BEGIN=pc_range_low][/END=pc_range_high]

FLT Lists the FLT commands.
FLT STOP TRACE Stops tracing.
FLT SHOW TRACE Displays detailed information about the trace. The following qualifier is available:

/SUMMARY
Displays the results sorted by the program counter (PC) that has incurred the most alignment faults.


FLT

Lists the FLT commands.

Format

FLT


Parameters

None.

Qualifiers

None.

Description

When entered by itself, the FLT command lists the available FLT commands.

Example


SDA> FLT 
      


FLT LOAD

Loads the FLT$DEBUG execlet. Do this before starting alignment fault tracing.

Format

FLT LOAD


Parameters

None.

Qualifiers

None.

Description

The FLT LOAD command loads the FLT$DEBUG execlet.

Example


SDA> FLT LOAD
      


FLT SHOW TRACE

Displays detail about the trace.

Format

FLT SHOW TRACE /SUMMARY


Parameters

None.

Qualifier

/SUMMARY

Displays the results sorted by the program counter (PC) that has incurred the most alignment faults.

Description

The FLT SHOW TRACE command displays detail about the trace.

Example


SDA> FLT SHOW TRACE
      


FLT START TRACE

Starts alignment fault tracing.

Format

START TRACE [/BUFFER=pages] [/BEGIN=pc_range_low][/END=pc_range_high]


Parameters

None.

Qualifiers

/BUFFER=pages

The number of pages to size the trace buffer. The default is 128 pages or 1MB.

/BEGIN=pc_range_low

Start of range of PCs to trace.

/END=pc_range_high

End of range of PCs to trace.

Description

The FLT START TRACE command starts alignment fault tracing. By default, all PCs are traced.

Example


SDA> FLT START TRACE
      


FLT STOP TRACE

Stops tracing.

Format

FLT STOP TRACE


Parameters

None.

Qualifiers

None.

Description

The FLT STOP TRACE command stops tracing.

Example


SDA> FLT STOP TRACE
      


FLT UNLOAD

Unloads the FLT$DEBUG execlet.

Format

FLT UNLOAD


Parameters

None.

Qualifiers

None.

Description

The FLT UNLOAD command unloads the FLT$DEBUG execlet.

Example


SDA> FLT UNLOAD
      


Chapter 8
SDA Spinlock Tracing Utility (SPL)

This chapter presents an overview of the SDA Spinlock Tracing Utility commands, and describes the SDA Spinlock Tracing commands.

8.1 Overview of the SDA Spinlock Tracing Utility

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.

8.2 How to Use the SDA Spinlock Tracing Utility

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
    

8.3 Example Command Procedure for Collection of Spinlock 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.

8.4 SDA Spinlock Tracing Commands

The following is a list of the spinlock tracing commands:

SPL ANALYZE
SPL LOAD
SPL SHOW COLLECT
SPL SHOW TRACE
SPL START COLLECT
SPL START TRACE
SPL STOP COLLECT
SPL STOP TRACE
SPL UNLOAD

SPL 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)]


Parameters

None.

Qualifiers

/CPU_STATISTICS (default)

/NOCPU_STATISTICS

Displays per-CPU statistics.

/PLATFORM (default)

/NOPLATFORM

Displays system platform information.

/HOLD_TIMES=n

/NOHOLD_TIMES=n

Displays occurrences of spinlocks held longer than n microseconds. The default is 1000 microseconds.

/WAIT_TIMES=n

/NOWAIT_TIMES=n

Displays occurrences of spinlocks held longer than n microseconds. The default is 1000 microseconds.

/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.


Description

The SPL ANALYZE command analyzes collected spinlock data and displays the most relevant data.

The SPL ANALYZE command provides an overview of SPINLOCK usage on a system. Data are provided by CPU and by spinlock. When looking at a system with high MP_Synch time, this is a good command to start with. Stop spinlock tracing before using this command.


Example


SDA> SPL ANALYZE/HOLD=50/WAIT=50/USAGE=HOLD=5 
 
Spinlock Analysis (1) 
 
 Platform 
 ------------------------------------------------ 
 Node:  CLU21   
 Hardware: AlphaServer ES45 Model 2 
 Active CPUs: 4 
 Memory:  16.00 GB 
 CPU Frequency: 1.000 GHz 
 
 Trace Buffer: 1280 pages (10.00 MB) 
 Trace Time: 0.48 seconds 
 Trace Start: 15-OCT 10:51:53.427386 
 
CPU statistics (2) 
                % Time in           % Time          % Time      All Spinlocks  All Spinlocks 
CPU ID    Fork Dispatcher   Spinlocks Held        MP_Synch       Acquires/sec      Waits/sec 
------    ---------------   --------------      ----------      -------------  ------------- 
    00                0.1             16.2             1.1            82210.4         1434.7 
    01                0.1             15.8             1.2            79551.5         1548.3 
    02                0.0             16.4             1.2            85690.9         1511.1 
    03                1.7             17.7             1.1            86601.3         1451.2 
------    ---------------   --------------      ----------      -------------  ------------- 
 Total                1.9             66.1             4.6           334054.1         5945.3 
 
Spinlock Usage (3) 
                                                                                                    Spin to 
Spinlock      % Time Held Acquires/sec Average Hold % Time Spinning    Waits/sec  Average Spin   Hold Ratio 
------------  ----------- ------------ ------------ --------------- ------------  ------------  ----------- 
FILSYS               15.6      33776.8         4609             2.6       2314.1         11379          0.2 
LCKMGR                9.3      26198.6         3560             1.2       2208.8          5494          0.1 
PCB$00000426          7.2      49420.4         1451             0.0         35.1          6342          0.0 
PCB$00000428          7.1      49125.2         1437             0.0         14.5          7532          0.0 
 
 
Spinlock    (4)                                         % Time   Acquires             Spinwaits    Average 
        Caller's PC                                       Held       /sec    Average       /sec   Spinwait 
        ----------------------------------------------  ------  ---------  ---------  ---------  --------- 
FILSYS      
        8022CA44  SEARCH_FCB_C+00604                      12.0     4021.3      29793      303.5      11985 
        80222E10  SET_DIRINDX_C+00030                      0.5     4194.7       1163      247.7      11477 
        8021B06C  START_REQUEST_C+0006C                    0.4     2438.0       1607      384.0      15838 
        8021B208  FINISH_REQUEST_C+00058                   0.4     2440.1       1510      206.4      15862 
        800FC508  IOC_STD$MAPVBLK_C+000C8                  0.3     2014.8       1713      402.5       9518 
LCKMGR      
        801DEB14  EXE$ENQ_C+00A44                          3.5    12984.7       2657      988.8       5727 
        801E3B94  EXE$DEQ_C+00114                          3.0     5943.2       5109      538.8       4849 
        801E03BC  LOCKING+023BC                            2.6     5941.2       4315      392.2       5682 
        801E5C84  LCK$DEQLOCK_C+00F54                      0.3     1323.2       2091      289.0       5642 
PCB$00000426 
        801782F8  SCH$ASTDEL_C+00078                       1.9    15525.9       1256        0.0          0 
        80179AC4  SCH$QAST_C+00094                         1.7     8907.6       1935        0.0          0 
        8017A780  SCH$QUEUE_AST_CURRENT_C+00070            1.2     7859.0       1532        0.0          0 
        80178FE0  SCH$ASTDEL_K_C+00090                     1.2     8895.3       1320        8.3       2346 
        80179124  SCH$ASTDEL_K_C+001D4                     1.1     7780.5       1355        0.0          0 
PCB$00000428 
        801782F8  SCH$ASTDEL_C+00078                       2.0    15606.4       1308        0.0          0 
        80179AC4  SCH$QAST_C+00094                         1.6     8810.6       1794        0.0          0 
        80178FE0  SCH$ASTDEL_K_C+00090                     1.2     8810.6       1344        6.2       2589 
        8017A780  SCH$QUEUE_AST_CURRENT_C+00070            1.2     7904.4       1492        0.0          0 
        80179124  SCH$ASTDEL_K_C+001D4                     1.0     7728.9       1340        0.0          0 
        8017A780  SCH$QUEUE_AST_CURRENT_C+00070            1.1     8655.8       1298        0.0          0 
        80179124  SCH$ASTDEL_K_C+001D4                     1.1     8598.0       1225        0.0          0 
        80178FE0  SCH$ASTDEL_K_C+00090                     1.1     9192.5       1144        2.1       2326 
 
Long Spinlock Hold Times (> 50 microseconds) (5) 
 
Timestamp              CPU Spinlock | Forklock   Calling PC | Forking PC                EPID      Hold (us) 
---------------------- --- --------------------- -------------------------------------- --------  --------- 
15-OCT 10:51:53.801244  00 81D6A200 81D6A200     8051B380 LAN$COMPLETE_VCRP_CSMACD_C+00 00000000         64 
15-OCT 10:51:53.538665  00 818BBE00 POOL         8004B334 EXE$ALONPAGVAR_C+002F4        00000000         59 
15-OCT 10:51:53.538331  03 81F75980 PCB$00000429 8017A808 SCH$QUEUE_AST_CURRENT_C+000F8 00000000         56 
15-OCT 10:51:53.597448  03 818BBE00 POOL         8004B334 EXE$ALONPAGVAR_C+002F4        00000000         52 
15-OCT 10:51:53.670228  03 818BBE00 POOL         8004B334 EXE$ALONPAGVAR_C+002F4        00000000         51 
 
Long Spinlock Wait Times (> 50 microseconds) (6) 
 
Timestamp              CPU Spinlock | Forklock   Calling PC | Forking PC                EPID      Wait (us) 
---------------------- --- --------------------- -------------------------------------- --------  --------- 
15-OCT 10:51:53.454082  03 818BCB00 FILSYS       800FC508 IOC_STD$MAPVBLK_C+000C8       00000000         79 
15-OCT 10:51:53.661343  02 818BCB00 FILSYS       8021B208 FINISH_REQUEST_C+00058        00000000         76 
15-OCT 10:51:53.661256  00 818BCB00 FILSYS       8021EDD0 F11BXQP+08DD0                 00000000         66 
15-OCT 10:51:53.898618  00 818BCB00 FILSYS       8021B06C START_REQUEST_C+0006C         00000000         53 
 

This example shows the output of the SPL ANALYZE command, which is divided into several sections:

  1. Spinlock Analysis:
    Shows information on the platform such as the hardware type, the number of CPUs and the speed of the CPUs.
  2. CPU Statistics:
    Shows spinlock information on a per CPU basis. The percentage of time the CPU owns spinlock is displayed along with a percentage of time the CPU was executing from the fork dispatcher. This information can be very useful in determing the amount of time a CPU is in use for processing I/O.
  3. Spinlock Usage:
    Shows information on the spinlock usage by the system. This data is sorted by the percentage of time the spinlocks are held. The average hold time displayed is in system cycles. The display also includes the percent of time that CPUs are waiting on this spinlock along with the average number of cycles a CPU needed to wait before it was able to acquire the spinlock.
  4. Spinlock:
    For each spinlock displayed in section 3, the top callers are displayed sorted by the number of acquires per second that occurred. In addition, the average hold and wait time for each caller is displayed in system cycles.
  5. Long Spinlock Hold Times:
    The section on Long Spinlock Hold Times shows occurrences of spinlocks whose hold time exceeded a threshold. In the above report, the threshold was specified as 50 microseconds. The EPID at the time of the acquire is also displayed. An EPID of 0 indicates that the spinlock acquire did not occur in process context.
  6. Long Spinlock Wait Times:
    The section on Long Spinlock Wait Times shows occurrences of spinlocks whose wait time exceeded a threshold. In the above report, the threshold was specified as 50 microseconds. The EPID at the time of the acquire is also displayed. An EPID of 0 indicates that the spinlock acquire did not occur in process context.


Previous Next Contents Index