cddl/contrib/dtracetoolkit/Examples/j_cpudist_example.txt

   1 This is an example of j_cpudist.d showing the elapsed times for different
   2 types of Java operations.
   3
   4 This traces activity from all Java processes on the system with hotspot
   5 provider support (1.6.0), and produces the output in graphical format, showing
   6 a histogram of the amount of time taken by each call. Method calls are only
   7 visible when using the flag "+ExtendedDTraceProbes". eg,
   8 java -XX:+ExtendedDTraceProbes classfile
   9
  10 Because of the extensive results returned otherwise, this script will show you
  11 a configurable number of results in each section.  The default (as in this
  12 example) is ten.
  13
  14 Here we see it tracing the activity of Code/Java/Func_abc.
  15
  16 # j_cpudist.d
  17 Tracing... Hit Ctrl-C to end.
  18 ^C
  19
  20 Top 10 on-CPU times (us),
  21
  22 Top 10 exclusive method on-CPU times (us),
  23    PID=311364, method, java/lang/AbstractStringBuilder.append
  24            value  ------------- Distribution ------------- count
  25                0 |                                         0
  26                1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@             382
  27                2 |@@@@@@@@@@@                              151
  28                4 |@                                        13
  29                8 |                                         1
  30               16 |                                         1
  31               32 |                                         1
  32               64 |                                         0
  33
  34    PID=311364, method, java/util/Arrays.copyOf
  35            value  ------------- Distribution ------------- count
  36                1 |                                         0
  37                2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          68
  38                4 |@@@@@@@                                  15
  39                8 |                                         0
  40               16 |                                         0
  41               32 |                                         1
  42               64 |                                         1
  43              128 |                                         0
  44              256 |@                                        2
  45              512 |                                         0
  46
  47    PID=311364, method, java/io/UnixFileSystem.normalize
  48            value  ------------- Distribution ------------- count
  49                1 |                                         0
  50                2 |@                                        1
  51                4 |                                         0
  52                8 |@@@@@@@@@@@                              9
  53               16 |@@@@@@@@@@@@@@                           12
  54               32 |@@@@@@                                   5
  55               64 |@@@@@@@                                  6
  56              128 |@                                        1
  57              256 |                                         0
  58
  59    PID=311364, method, java/io/File.<clinit>
  60            value  ------------- Distribution ------------- count
  61              512 |                                         0
  62             1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  63             2048 |                                         0
  64
  65    PID=311364, method, sun/misc/URLClassPath$JarLoader.getJarFile
  66            value  ------------- Distribution ------------- count
  67              512 |                                         0
  68             1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
  69             2048 |                                         0
  70
  71    PID=311364, method, java/io/FilePermission$1.run
  72            value  ------------- Distribution ------------- count
  73                1 |                                         0
  74                2 |@@@@@@@@@@@@@@@@@@@@                     2
  75                4 |@@@@@@@@@@                               1
  76                8 |                                         0
  77               16 |                                         0
  78               32 |                                         0
  79               64 |                                         0
  80              128 |                                         0
  81              256 |                                         0
  82              512 |                                         0
  83             1024 |@@@@@@@@@@                               1
  84             2048 |                                         0
  85
  86    PID=311364, method, java/lang/StringBuilder.append
  87            value  ------------- Distribution ------------- count
  88                1 |                                         0
  89                2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  526
  90                4 |                                         2
  91                8 |                                         0
  92               16 |                                         4
  93               32 |                                         1
  94               64 |                                         0
  95
  96    PID=311364, method, java/lang/String.<init>
  97            value  ------------- Distribution ------------- count
  98                1 |                                         0
  99                2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@    162
 100                4 |@@                                       10
 101                8 |                                         0
 102               16 |                                         0
 103               32 |                                         0
 104               64 |                                         1
 105              128 |                                         0
 106              256 |                                         1
 107              512 |                                         0
 108             1024 |                                         1
 109             2048 |                                         0
 110
 111    PID=311364, method, java/lang/String.charAt
 112            value  ------------- Distribution ------------- count
 113                0 |                                         0
 114                1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1953
 115                2 |                                         3
 116                4 |                                         1
 117                8 |                                         1
 118               16 |                                         2
 119               32 |                                         0
 120
 121    PID=311364, method, java/lang/System.initializeSystemClass
 122            value  ------------- Distribution ------------- count
 123             1024 |                                         0
 124             2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 125             4096 |                                         0
 126
 127
 128 Top 10 inclusive method on-CPU times (us),
 129    PID=311364, method, sun/misc/Launcher$ExtClassLoader.<init>
 130            value  ------------- Distribution ------------- count
 131             8192 |                                         0
 132            16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 133            32768 |                                         0
 134
 135    PID=311364, method, sun/misc/Launcher$ExtClassLoader.getExtClassLoader
 136            value  ------------- Distribution ------------- count
 137             8192 |                                         0
 138            16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 139            32768 |                                         0
 140
 141    PID=311364, method, sun/misc/Launcher$ExtClassLoader.getExtURLs
 142            value  ------------- Distribution ------------- count
 143             8192 |                                         0
 144            16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 145            32768 |                                         0
 146
 147    PID=311364, method, sun/misc/Launcher.<clinit>
 148            value  ------------- Distribution ------------- count
 149             8192 |                                         0
 150            16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 151            32768 |                                         0
 152
 153    PID=311364, method, sun/misc/Launcher.<init>
 154            value  ------------- Distribution ------------- count
 155             8192 |                                         0
 156            16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
 157            32768 |                                         0
 158
 159    PID=311364, method, java/lang/ClassLoader.loadClassInternal
 160            value  ------------- Distribution ------------- count
 161               32 |                                         0
 162               64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@              6
 163              128 |@@@@@@@@@                                2
 164              256 |                                         0
 165              512 |                                         0
 166             1024 |                                         0
 167             2048 |                                         0
 168             4096 |                                         0
 169             8192 |                                         0
 170            16384 |@@@@                                     1
 171            32768 |                                         0
 172
 173    PID=311364, method, sun/misc/Launcher$AppClassLoader.loadClass
 174            value  ------------- Distribution ------------- count
 175               32 |                                         0
 176               64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@              6
 177              128 |@@@@@@@@@                                2
 178              256 |                                         0
 179              512 |                                         0
 180             1024 |                                         0
 181             2048 |                                         0
 182             4096 |                                         0
 183             8192 |                                         0
 184            16384 |@@@@                                     1
 185            32768 |                                         0
 186
 187    PID=311364, method, sun/misc/URLClassPath.getLoader
 188            value  ------------- Distribution ------------- count
 189                2 |                                         0
 190                4 |@@@                                      1
 191                8 |                                         0
 192               16 |                                         0
 193               32 |                                         0
 194               64 |                                         0
 195              128 |                                         0
 196              256 |@@@                                      1
 197              512 |@@@@@@@@@@@@@@@@@@@@@@                   7
 198             1024 |@@@@@@                                   2
 199             2048 |                                         0
 200             4096 |@@@                                      1
 201             8192 |@@@                                      1
 202            16384 |                                         0
 203
 204    PID=311364, method, java/lang/ClassLoader.loadClass
 205            value  ------------- Distribution ------------- count
 206               16 |                                         0
 207               32 |@@@@@@@@@                                6
 208               64 |@@@@@@@@@@@@@@@@@@@@@                    14
 209              128 |@@@@@@                                   4
 210              256 |                                         0
 211              512 |                                         0
 212             1024 |                                         0
 213             2048 |                                         0
 214             4096 |                                         0
 215             8192 |@                                        1
 216            16384 |@@@                                      2
 217            32768 |                                         0
 218
 219    PID=311364, method, java/security/AccessController.doPrivileged
 220            value  ------------- Distribution ------------- count
 221                2 |                                         0
 222                4 |@                                        1
 223                8 |@@@@                                     4
 224               16 |@@@@@@@@@@                               11
 225               32 |@@@@@@@@@@                               11
 226               64 |                                         0
 227              128 |@@@                                      3
 228              256 |@                                        1
 229              512 |@@@@@                                    5
 230             1024 |@@                                       2
 231             2048 |@                                        1
 232             4096 |@                                        1
 233             8192 |@@                                       2
 234            16384 |@                                        1
 235            32768 |                                         0
 236
 237 The elapsed times section is empty.  It would show us anything that is not a
 238 Java method - garbage collection for example.  However there was nothing of
 239 the kind in this example.
 240
 241 The exclusive method elapsed times show us the time spent on-CPU by the most
 242 time consuming methods, not including time spent in subroutines called by
 243 those methods.
 244
 245 The inclusive method elapsed times show us the time spent on-CPU by the top
 246 ten most time consuming methods including time spent in subroutines called by
 247 those methods.
 248
 249 It is important to pay close attention to the third column, "count" as this
 250 will indicate if there were any instances in a particular timeframe, even if
 251 the number is too small to show up on the histogram clearly.
 252