cddl/contrib/dtracetoolkit/Examples/shortlived_example.txt

   1 The following is an example of the shortlived.d program.
   2 It can measure time spent processing short lived processes,
   3 that may be responsible for heavy load on the system but
   4 are usually difficult to see with sampling tools like prstat.
   5
   6
   7
   8 Here we run in for a few seconds on a server,
   9
  10    # shortlived.d
  11    Tracing... Hit Ctrl-C to stop.
  12    ^C
  13    short lived processes:      0.456 secs
  14    total sample duration:      9.352 secs
  15
  16    Total time by process name,
  17                  date           12 ms
  18                    df           20 ms
  19                    ls           40 ms
  20                  perl          380 ms
  21
  22    Total time by PPID,
  23                  3279          452 ms
  24
  25 In the above output, around 5% of the CPU was lost to short
  26 lived processes - mostly perl. This may be many perl processes,
  27 here we are aggregating on the process name not the instance.
  28
  29
  30
  31 Now shortlived.d is run on a server with a performance problem,
  32
  33    # uptime
  34      10:58pm  up 5 day(s),  1:28,  1 user,  load average: 2.20, 1.81, 1.04
  35    #
  36    # shortlived.d
  37    Tracing... Hit Ctrl-C to stop.
  38    ^C
  39    short lived processes:      4.546 secs
  40    total sample duration:      9.858 secs
  41
  42    Total time by process name,
  43                  expr         4122 ms
  44
  45    Total time by PPID,
  46                  3279         4122 ms
  47    #
  48    # ps -p 3279
  49       PID TTY         TIME CMD
  50      3279 pts/10      0:45 report.sh
  51
  52 shortlived.d showed that 50% of the CPU was consumed by short lived
  53 processes, all of them the "expr" command, and all having the
  54 parent proccess-ID 3279. We finished by checking PID 3279 to find
  55 it is a Bourne shell script called "report.sh".
  56
  57