Using the pprof command to measure microprocessor usage of kernel threads
The pprof command reports microprocessor usage on all kernel threads running within an interval using the trace utility.
The raw process information is saved to pprof.flow and five reports are generated. If no flags are specified, all reports are generated.
To
determine whether the pprof program is installed and available,
run the following command:
# lslpp -lI bos.perf.toolsThe types of reports are as follows:
- pprof.cpu
- Lists all kernel level threads sorted by actual microprocessor time. Contains: Process Name, Process ID, Parent Process ID, Process State at Beginning and End, Thread ID, Parent Thread ID, Actual CPU Time, Start Time, Stop Time, Stop - Start.
- pprof.famcpu
- Lists the information for all families (processes with a common ancestor). The Process Name and Process ID for the family is not necessarily the ancestor. Contains: Start Time, Process Name, Process ID, Number of Threads, Total CPU Time.
- pprof.famind
- Lists all processes grouped by families (processes with a common ancestor). Child process names are indented with respect to the parent. Contains: Start Time, Stop Time, Actual CPU Time, Process ID, Parent Process ID, Thread ID, Parent Thread ID, Process State at Beginning and End, Level, Process Name.
- pprof.namecpu
- Lists information about each type of kernel thread (all executable with the same name). Contains: Process Name, Number of Threads, CPU Time, % of Total CPU Time.
- pprof.start
- Lists all kernel threads sorted by start time that were dispatched during the pprof command interval. Contains: Process Name, Process ID, Parent Process ID, Process State Beginning and End, Thread ID, Parent Thread ID, Actual CPU Time, Start Time, Stop Time, Stop - Start.
Following is a sample pprof.namecpu file
that was generated by running the tthreads32 program, which forks off
four threads, which in turn each fork off a process of their own. These processes
then execute several ksh and sleep programs:
Pprof PROCESS NAME Report
Sorted by CPU Time
From: Thu Oct 19 17:53:07 2000
To: Thu Oct 19 17:53:22 2000
Pname #ofThreads CPU_Time %
======== ========== ======== ========
tthreads32 13 0.116 37.935
sh 8 0.092 30.087
Idle 2 0.055 17.987
ksh 12 0.026 8.503
trace 3 0.007 2.289
java 3 0.006 1.962
kproc 5 0.004 1.308
xmservd 1 0.000 0.000
trcstop 1 0.000 0.000
swapper 1 0.000 0.000
gil 1 0.000 0.000
ls 4 0.000 0.000
sleep 9 0.000 0.000
ps 4 0.000 0.000
syslogd 1 0.000 0.000
nfsd 2 0.000 0.000
========== ======== ========
70 0.306 100.000The
corresponding pprof.cpu is as follows:
Pprof CPU Report
Sorted by Actual CPU Time
From: Thu Oct 19 17:53:07 2000
To: Thu Oct 19 17:53:22 2000
E = Exec'd F = Forked
X = Exited A = Alive (when traced started or stopped)
C = Thread Created
Pname PID PPID BE TID PTID ACC_time STT_time STP_time STP-STT
===== ===== ===== === ===== ===== ======== ======== ======== ========
Idle 774 0 AA 775 0 0.052 0.000 0.154 0.154
tthreads32 5490 11982 EX 18161 22435 0.040 0.027 0.154 0.126
sh 11396 5490 EE 21917 5093 0.035 0.082 0.154 0.072
sh 14106 5490 EE 16999 18867 0.028 0.111 0.154 0.043
sh 13792 5490 EE 20777 18179 0.028 0.086 0.154 0.068
ksh 5490 11982 FE 18161 22435 0.016 0.010 0.027 0.017
tthreads32 5490 11982 CX 5093 18161 0.011 0.056 0.154 0.098
tthreads32 5490 11982 CX 18179 18161 0.010 0.054 0.154 0.099
tthreads32 14506 5490 FE 17239 10133 0.010 0.128 0.143 0.015
ksh 11982 13258 AA 22435 0 0.010 0.005 0.154 0.149
tthreads32 13792 5490 FE 20777 18179 0.010 0.059 0.086 0.027
tthreads32 5490 11982 CX 18867 18161 0.010 0.057 0.154 0.097
tthreads32 11396 5490 FE 21917 5093 0.009 0.069 0.082 0.013
tthreads32 5490 11982 CX 10133 18161 0.008 0.123 0.154 0.030
tthreads32 14106 5490 FE 16999 18867 0.008 0.088 0.111 0.023
trace 5488 11982 AX 18159 0 0.006 0.001 0.005 0.003
kproc 1548 0 AA 2065 0 0.004 0.071 0.154 0.082
Idle 516 0 AA 517 0 0.003 0.059 0.154 0.095
java 11612 11106 AA 14965 0 0.003 0.010 0.154 0.144
java 11612 11106 AA 14707 0 0.003 0.010 0.154 0.144
trace 12544 5488 AA 20507 0 0.001 0.000 0.001 0.001
sh 14506 5490 EE 17239 10133 0.001 0.143 0.154 0.011
trace 12544 5488 CA 19297 20507 0.000 0.001 0.154 0.153
ksh 4930 2678 AA 5963 0 0.000 0.154 0.154 0.000
kproc 6478 0 AA 3133 0 0.000 0.154 0.154 0.000
ps 14108 5490 EX 17001 18867 0.000 0.154 0.154 0.000
tthreads32 13794 5490 FE 20779 18179 0.000 0.154 0.154 0.000
sh 13794 5490 EE 20779 18179 0.000 0.154 0.154 0.000
ps 13794 5490 EX 20779 18179 0.000 0.154 0.154 0.000
sh 14108 5490 EE 17001 18867 0.000 0.154 0.154 0.000
tthreads32 14108 5490 FE 17001 18867 0.000 0.154 0.154 0.000
ls 13792 5490 EX 20777 18179 0.000 0.154 0.154 0.000
:
:
: