Home | History | Annotate | Line # | Download | only in Examples
      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 
     76