cddl/contrib/dtracetoolkit/Examples/j_cputime_example.txt

   1 The following are examples of j_cputime.d.
   2
   3 This script traces the on-CPU time of Java methods and prints a report. Here
   4 it traces the example program, Code/Java/Func_abc
   5
   6 # j_cputime.d
   7 Tracing... Hit Ctrl-C to end.
   8 ^C
   9
  10 Top 10 counts,
  11       PID TYPE       NAME                                                COUNT
  12    311374 method     java/lang/String.equals                               202
  13    311374 method     java/lang/Math.min                                    208
  14    311374 method     java/lang/String.hashCode                             213
  15    311374 method     java/lang/String.indexOf                              302
  16    311374 method     java/lang/System.arraycopy                            360
  17    311374 method     java/lang/StringBuilder.append                        533
  18    311374 method     java/lang/AbstractStringBuilder.append                549
  19    311374 method     java/lang/Object.<init>                               823
  20    311374 method     java/lang/String.charAt                              1960
  21         0 total      -                                                   12020
  22
  23 Top 10 on-CPU times (us),
  24       PID TYPE       NAME                                                TOTAL
  25
  26 Top 10 exclusive method on-CPU times (us),
  27       PID TYPE       NAME                                                TOTAL
  28    311374 method     java/io/FilePermission$1.run                         1055
  29    311374 method     java/util/Arrays.copyOf                              1110
  30    311374 method     sun/net/www/ParseUtil.decode                         1161
  31    311374 method     java/io/File.<clinit>                                1212
  32    311374 method     java/lang/StringBuilder.append                       1228
  33    311374 method     java/io/UnixFileSystem.normalize                     1402
  34    311374 method     java/lang/String.<init>                              2251
  35    311374 method     java/lang/String.charAt                              2262
  36    311374 method     java/lang/System.initializeSystemClass               2751
  37         0 total      -                                                   99868
  38
  39 Top 10 inclusive method on-CPU times (us),
  40       PID TYPE       NAME                                                TOTAL
  41    311374 method     java/lang/ClassLoader.loadClassInternal             25826
  42    311374 method     sun/misc/Launcher$ExtClassLoader.getExtClassLoader    25914
  43    311374 method     java/net/URL.<init>                                 27677
  44    311374 method     sun/misc/Launcher.<init>                            28566
  45    311374 method     sun/misc/Launcher.<clinit>                          28744
  46    311374 method     java/lang/ClassLoader.initSystemClassLoader         29241
  47    311374 method     java/lang/ClassLoader.getSystemClassLoader          29249
  48    311374 method     java/lang/System.initializeSystemClass              33814
  49    311374 method     java/lang/ClassLoader.loadClass                     66564
  50    311374 method     java/security/AccessController.doPrivileged         67499
  51
  52 You can see that it prints the top ten results in each of four categories.
  53
  54 The first section reports how many times each subroutine was called, and it's
  55 type.
  56
  57 The second section reports on the on-CPU time of anything that was not of type
  58 "method", in this case - none.
  59
  60 The exclusive method on-CPU times shows, amongst other results, that
  61 java/lang/String.charAt spent around 2,200 microseconds on-CPU.  This times
  62 excludes time spent in other subroutines.
  63
  64 The inclusive method on-CPU times show the times that various methods
  65 spent on-CPU.  This includes the time spent in other subroutines called.
  66
  67 These on-CPU times are the time the thread spent running on a CPU, from when
  68 the subroutine began to when it completed. This does not include time
  69 spent off-CPU time such as sleeping for I/O or waiting for scheduling.
  70
  71 On-CPU times are useful for showing who is causing the CPUs to be busy.
  72 See Notes/ALLoncpu_notes.txt for more details. Also see
  73 Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a
  74 detailed explanation of exclusive vs inclusive subroutine time.
  75