cddl/contrib/dtracetoolkit/Examples/tcl_cpudist_example.txt

   1 The following are examples of tcl_cpudist.d.
   2
   3 This script traces the on-CPU time of Tcl commands and procedures and
   4 prints a report containing distribution plots per subroutine. Here it
   5 traces the example program, Code/Tcl/func_slow.tcl.
   6
   7 # tcl_cpudist.d
   8 Tracing... Hit Ctrl-C to end.
   9 ^C
  10
  11 Top 10 exclusive on-CPU times (us),
  12    PID=16043, cmd, info
  13            value  ------------- Distribution ------------- count
  14                0 |                                         0
  15                1 |@@@@                                     1
  16                2 |@@@@@@@@@@@@@@@                          4
  17                4 |@@@@                                     1
  18                8 |@@@@                                     1
  19               16 |@@@@@@@@@@@                              3
  20               32 |@@@@                                     1
  21               64 |                                         0
  22
  23    PID=16043, cmd, namespace
  24            value  ------------- Distribution ------------- count
  25                0 |                                         0
  26                1 |@@@@@@@@@@@@@                            1
  27                2 |@@@@@@@@@@@@@                            1
  28                4 |                                         0
  29                8 |                                         0
  30               16 |                                         0
  31               32 |                                         0
  32               64 |                                         0
  33              128 |@@@@@@@@@@@@@                            1
  34              256 |                                         0
  35
  36    PID=16043, cmd, puts
  37            value  ------------- Distribution ------------- count
  38               16 |                                         0
  39               32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@              2
  40               64 |                                         0
  41              128 |@@@@@@@@@@@@@                            1
  42              256 |                                         0
  43
  44    PID=16043, cmd, if
  45            value  ------------- Distribution ------------- count
  46                4 |                                         0
  47                8 |@@@@@@@@@@                               2
  48               16 |@@@@@@@@@@@@@@@@@@@@                     4
  49               32 |@@@@@                                    1
  50               64 |                                         0
  51              128 |@@@@@                                    1
  52              256 |                                         0
  53
  54    PID=16043, cmd, tclInit
  55            value  ------------- Distribution ------------- count
  56              128 |                                         0
  57              256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  58              512 |                                         0
  59
  60    PID=16043, cmd, file
  61            value  ------------- Distribution ------------- count
  62                2 |                                         0
  63                4 |@@@@@@@@@@@@@                            4
  64                8 |@@@@@@@@@@@@@                            4
  65               16 |                                         0
  66               32 |@@@                                      1
  67               64 |@@@@@@@@@@                               3
  68              128 |                                         0
  69
  70    PID=16043, cmd, source
  71            value  ------------- Distribution ------------- count
  72              256 |                                         0
  73              512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  74             1024 |                                         0
  75
  76    PID=16043, proc, func_a
  77            value  ------------- Distribution ------------- count
  78           262144 |                                         0
  79           524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  80          1048576 |                                         0
  81
  82    PID=16043, proc, func_b
  83            value  ------------- Distribution ------------- count
  84           524288 |                                         0
  85          1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  86          2097152 |                                         0
  87
  88    PID=16043, proc, func_c
  89            value  ------------- Distribution ------------- count
  90           524288 |                                         0
  91          1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  92          2097152 |                                         0
  93
  94
  95 Top 10 inclusive on-CPU times (us),
  96    PID=16043, cmd, source
  97            value  ------------- Distribution ------------- count
  98              512 |                                         0
  99             1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 100             2048 |                                         0
 101
 102    PID=16043, cmd, uplevel
 103            value  ------------- Distribution ------------- count
 104              512 |                                         0
 105             1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 106             2048 |                                         0
 107
 108    PID=16043, proc, tclInit
 109            value  ------------- Distribution ------------- count
 110              512 |                                         0
 111             1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 112             2048 |                                         0
 113
 114    PID=16043, cmd, tclInit
 115            value  ------------- Distribution ------------- count
 116             1024 |                                         0
 117             2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 118             4096 |                                         0
 119
 120    PID=16043, cmd, func_c
 121            value  ------------- Distribution ------------- count
 122           524288 |                                         0
 123          1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 124          2097152 |                                         0
 125
 126    PID=16043, proc, func_c
 127            value  ------------- Distribution ------------- count
 128           524288 |                                         0
 129          1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 130          2097152 |                                         0
 131
 132    PID=16043, cmd, func_a
 133            value  ------------- Distribution ------------- count
 134          1048576 |                                         0
 135          2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 136          4194304 |                                         0
 137
 138    PID=16043, cmd, func_b
 139            value  ------------- Distribution ------------- count
 140          1048576 |                                         0
 141          2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 142          4194304 |                                         0
 143
 144    PID=16043, proc, func_a
 145            value  ------------- Distribution ------------- count
 146          1048576 |                                         0
 147          2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 148          4194304 |                                         0
 149
 150    PID=16043, proc, func_b
 151            value  ------------- Distribution ------------- count
 152          1048576 |                                         0
 153          2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 154          4194304 |                                         0
 155
 156 These on-CPU times are the time the thread spent running on a CPU, from when
 157 the subroutine began to when it completed. This does not include time
 158 spent off-CPU time such as sleeping for I/O or waiting for scheduling.
 159
 160 On-CPU times are useful for showing who is causing the CPUs to be busy.
 161 See Notes/ALLoncpu_notes.txt for more details. Also see
 162 Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a
 163 detailed explanation of exclusive vs inclusive subroutine time.
 164