IBM Power7 - AIX Trace-Based Analysis Tools

Appendix B. Performance tooling and empirical performance analysis 165
AIX trace-based analysis tools
Trac e
1
is a powerful utility that is provided by AIX for collecting a time-sequenced log of
operating system events on a Power Systems server. The AIX kernel and kernel extensions
are richly instrumented with trace
hooks that, when trace is activated, append trace records
with context-relevant data, to a pinned, kernel-resident trace buffer. These records can be
later read from that buffer and logged to a disk-resident file. Further utilities are provided to
interpret and summarize trace logs and generate human-readable reports. The tprof CPU
profiler is one such utility. Besides tprof, two of the most-commonly used trace-based utilities
are curt
2
and splat.
3,4
The curt command takes as its input a trace collected using the AIX trace facility, and
generates a report that breaks down how CPU time is consumed by various
entities, including:
򐂰 Processes (grouped by process name)
򐂰 Individual processes
򐂰 Individual threads
򐂰 System calls (either on a system-wide or per-thread basis)
򐂰 Interrupts
One of the most useful reports from curt is the
System Calls Summary. This report provides a
system-wide summary of the system calls that are executed while the trace is collected. For
each system call, the following information is provided:
򐂰 Count: The number of times the system call was run during the monitoring interval
򐂰 Total Time: Amount of CPU time (in milliseconds) consumed in running the system call
򐂰 % sys time: Percentage of overall CPU capacity that is spent in running the system call
򐂰 Avg Time: Average CPU time that is consumed for each execution of the system call
򐂰 Min Time: Minimum CPU time that is consumed during an execution of the system call
򐂰 Max Time: Maximum CPU time that is consumed during an execution of the system call
򐂰 SVC: Name and address of the system call
An excerpt from a System Calls Summary report is shown in Example B-4.
Example B-4 System Calls Summary report (excerpt)
System Calls Summary
--------------------
Count Total Time % sys Avg Time Min Time Max Time SVC (Address)
(msec) time (msec) (msec) (msec)
======== =========== ====== ======== ======== ======== ================
123647 3172.0694 14.60% 0.0257 0.0128 0.9064 kpread(2a2d5e8)
539 1354.6939 6.24% 2.5133 0.0163 4.1719 listio64(516ea40)
26496 757.6204 3.49% 0.0286 0.0162 0.0580 _esend(2a29f88)
26414 447.7029 2.06% 0.0169 0.0082 0.0426 _erecv(2a29e98)
1
trace Daemon, available at:
http://publib.boulder.ibm.com/infocenter/aix/v7r1/index.jsp?topic=/com.ibm.aix.cmds/doc/aixcmds5/tra
ce.htm
2
CPU Utilization Reporting Tool (curt), available at:
http://pic.dhe.ibm.com/infocenter/aix/v7r1/topic/com.ibm.aix.prftools/doc/prftools/idprftools_cpu.ht
m
3
Simple performance lock analysis tool (splat), available at:
http://pic.dhe.ibm.com/infocenter/aix/v7r1/topic/com.ibm.aix.prftools/doc/prftools/idprftools_splat.ht
m
4
splat Command, available at:
http://publib.boulder.ibm.com/infocenter/aix/v7r1/index.jsp?topic=/com.ibm.aix.cmds/doc/aixcmds5/splat
.htm