cddl/contrib/dtracetoolkit/Examples/j_calltime_example.txt

   1 The following are examples of j_calltime.d.
   2
   3 This script traces the elapsed time of Java methods and prints a report of the
   4 top ten in each category.   This number is configurable with simple edit of
   5 the DTrace script
   6
   7 Here it traces the example program, Code/Java/Func_abc
   8
   9 # j_calltime.d
  10 Tracing... Hit Ctrl-C to end.
  11 ^C
  12
  13 Top 10 counts,
  14       PID TYPE       NAME                                                COUNT
  15    311358 method     java/lang/String.equals                               202
  16    311358 method     java/lang/Math.min                                    208
  17    311358 method     java/lang/String.hashCode                             213
  18    311358 method     java/lang/String.indexOf                              302
  19    311358 method     java/lang/System.arraycopy                            360
  20    311358 method     java/lang/StringBuilder.append                        533
  21    311358 method     java/lang/AbstractStringBuilder.append                549
  22    311358 method     java/lang/Object.<init>                               823
  23    311358 method     java/lang/String.charAt                              1960
  24         0 total      -                                                   12020
  25
  26 Top 10 elapsed times (us),
  27       PID TYPE       NAME                                                TOTAL
  28
  29 Top 10 exclusive method elapsed times (us),
  30       PID TYPE       NAME                                                TOTAL
  31    311358 method     java/nio/ByteBuffer.<init>                           5430
  32    311358 method     java/lang/String.charAt                              6079
  33    311358 method     java/lang/String.<init>                              7306
  34    311358 method     java/lang/StringBuilder.append                      10240
  35    311358 method     java/util/StringTokenizer.scanToken                 11075
  36    311358 method     java/net/URL.<clinit>                               12519
  37    311358 method     java/io/UnixFileSystem.normalize                    13218
  38    311358 method     sun/net/www/ParseUtil.decode                        14208
  39    311358 method     java/lang/Thread.sleep                            3016374
  40         0 total      -                                                 3344993
  41
  42 Top 10 inclusive method elapsed times (us),
  43       PID TYPE       NAME                                                TOTAL
  44    311358 method     sun/misc/Launcher.<clinit>                         129120
  45    311358 method     java/lang/ClassLoader.initSystemClassLoader        129851
  46    311358 method     java/lang/ClassLoader.getSystemClassLoader         129897
  47    311358 method     java/lang/ClassLoader.loadClass                    267404
  48    311358 method     java/security/AccessController.doPrivileged        278364
  49    311358 method     Func_abc.func_c                                   1009971
  50    311358 method     Func_abc.func_b                                   2019995
  51    311358 method     java/lang/Thread.sleep                            3016374
  52    311358 method     Func_abc.func_a                                   3027043
  53    311358 method     Func_abc.main                                     3027068
  54
  55 Counts shows us how many times each different method was called, and how
  56 many methods were called in total.
  57
  58 The exclusive method elapsed times show the time that each method spent
  59 processing code - while not in other method.
  60
  61 The inclusive method elapsed times show the time that each method spent
  62 processing code, including the time spent in other calls.
  63
  64 These elapsed times are the absolute time from when the method began to
  65 when it completed - which includes off-CPU time due to other system events
  66 such as I/O, scheduling, interrupts, etc.
  67