[ Previous | Next | Table of Contents | Index | Library Home | Legal | Search ]

Performance Management Guide

Using the pprof Command to Measure CPU usage of Kernel Threads

The pprof command reports CPU 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 (available with AIX 4.3.3 and later) is installed and available, run the following command: 

# lslpp -lI perfagent.tools

The types of reports are as follows:

pprof.cpu
Lists all kernel level threads sorted by actual CPU 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 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.000

The 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
:
:
:

[ Previous | Next | Table of Contents | Index | Library Home | Legal | Search ]