HP Caliper Ktrace Features Guide

Example Troubleshooting a Performance Problem
After upgrading an Operating System, the system's benchmark performance regressed
18%. The system configuration is the same as when the last benchmark was run with
the exception of a different root disk. Additional symptoms are:
• time (1M) indicates 627 seconds of real time were used vs 557 in the previous
benchmark. 28 seconds more of user time and 3 seconds more in system time.
• sar -d indicates 100 times longer disk avwait and avqueue.
• spinwatcher identifies more user time in sas, more kernel time in idle. Both previous
and new benchmarks spend the most time in processes sas and vxfsd, and the
most kernel CPU time is spent in vx_inode_free_list
Use ktracer to determine what changed as a result of the OS change and where the
slowdown is.
Procedure
Use ktracer to examine the kernel activity:
1. Trace the vxfsd process: ktracer -p 59
2. Select all functions in the vxfs module: ktracer -m vxfs
3. Run ktracer -b as sas begins.
4. Run ktracer -h as it ends.
5. Dump the traces and analyze them. ktracedump-D > out.
6. Observe that there is a lot of activity around functions vx_recsmp_rangelock
and vx_recsmp_rangeunlock.
7. Trace just these two locking functions and revert to tracing all processes to observe
rwlock contention.
ktracer -z -a vx_recsmp_rangelock -a vx_recsmp_rangeunlock
-p 0
Run ktracer iteratively to gain additional insight.
1. Start ktracer again when the last phase of sas begins: ktracer -Z -b
Stop (halt) ktracer before sas ends: ktracer -h
2. Invoke ktracedump to and add interesting trace fields ktracedump -J Caller
-J AbsSec -J arg0 -F". -F shows the two functions being traced.
3. Write a Perl script that parses ktracedump output and calculates recsmp range
lock hold duration based on AbsSec Diff, using arg0 to identify unique lock
addresses.
4. Discover that some range unlocks mid-run have no matching lock.
5. Search nm output and run ktracer -a vx_recsmp_rangetrylock so that all
vx_recsmp_range* lock functions are traced.
Isolate the performance regression.
24 ktracer: Kernel Tracer