cddl/contrib/dtracetoolkit/Java/j_calltime.d

   1 #!/usr/sbin/dtrace -CZs
   2 /*
   3  * j_calltime.d - measure Java elapsed times for different types of operation.
   4  *                Written for the Java hotspot DTrace provider.
   5  *
   6  * $Id: j_calltime.d 59 2007-10-03 08:21:58Z brendan $
   7  *
   8  * This traces activity from all Java processes on the system with hotspot
   9  * provider support (1.6.0). Method calls are only visible when using the
  10  * flag "+ExtendedDTraceProbes". eg, java -XX:+ExtendedDTraceProbes classfile
  11  *
  12  * USAGE: j_calltime.d [top]    # hit Ctrl-C to end
  13  *
  14  * The "top" optional argument will truncate the output for each report
  15  * section to that many lines, with a default of 10.
  16  *
  17  * FIELDS:
  18  *              PID             Process ID
  19  *              TYPE            Type of call (method/gc/total)
  20  *              NAME            Name of call
  21  *              TOTAL           Total elapsed time for calls (us)
  22  *
  23  * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
  24  *
  25  * CDDL HEADER START
  26  *
  27  *  The contents of this file are subject to the terms of the
  28  *  Common Development and Distribution License, Version 1.0 only
  29  *  (the "License").  You may not use this file except in compliance
  30  *  with the License.
  31  *
  32  *  You can obtain a copy of the license at Docs/cddl1.txt
  33  *  or http://www.opensolaris.org/os/licensing.
  34  *  See the License for the specific language governing permissions
  35  *  and limitations under the License.
  36  *
  37  * CDDL HEADER END
  38  *
  39  * 09-Sep-2007  Brendan Gregg   Created this.
  40  */
  41
  42 #define TOP     10              /* default output truncation */
  43 #define B_FALSE 0
  44
  45 #pragma D option quiet
  46 #pragma D option defaultargs
  47
  48 dtrace:::BEGIN
  49 {
  50         printf("Tracing... Hit Ctrl-C to end.\n");
  51         top = $1 != 0 ? $1 : TOP;
  52 }
  53
  54 hotspot*:::method-entry
  55 {
  56         self->depth[arg0]++;
  57         self->exclude[arg0, self->depth[arg0]] = 0;
  58         self->method[arg0, self->depth[arg0]] = timestamp;
  59 }
  60
  61 hotspot*:::method-return
  62 /self->method[arg0, self->depth[arg0]]/
  63 {
  64         this->elapsed_incl = timestamp - self->method[arg0, self->depth[arg0]];
  65         this->elapsed_excl = this->elapsed_incl -
  66             self->exclude[arg0, self->depth[arg0]];
  67         self->method[arg0, self->depth[arg0]] = 0;
  68         self->exclude[arg0, self->depth[arg0]] = 0;
  69
  70         this->class = (char *)copyin(arg1, arg2 + 1);
  71         this->class[arg2] = '\0';
  72         this->method = (char *)copyin(arg3, arg4 + 1);
  73         this->method[arg4] = '\0';
  74         this->name = strjoin(strjoin(stringof(this->class), "."),
  75             stringof(this->method));
  76
  77         @num[pid, "method", this->name] = count();
  78         @num[0, "total", "-"] = count();
  79         @types_incl[pid, "method", this->name] = sum(this->elapsed_incl);
  80         @types_excl[pid, "method", this->name] = sum(this->elapsed_excl);
  81         @types_excl[0, "total", "-"] = sum(this->elapsed_excl);
  82
  83         self->depth[arg0]--;
  84         self->exclude[arg0, self->depth[arg0]] += this->elapsed_incl;
  85 }
  86
  87 hotspot*:::gc-begin
  88 {
  89         self->gc = timestamp;
  90         self->full = (boolean_t)arg0;
  91 }
  92
  93 hotspot*:::gc-end
  94 /self->gc/
  95 {
  96         this->elapsed = timestamp - self->gc;
  97         self->gc = 0;
  98
  99         @num[pid, "gc", self->full == B_FALSE ? "GC" : "Full GC"] = count();
 100         @types[pid, "gc", self->full == B_FALSE ? "GC" : "Full GC"] =
 101             sum(this->elapsed);
 102         self->full = 0;
 103 }
 104
 105 dtrace:::END
 106 {
 107         trunc(@num, top);
 108         printf("\nTop %d counts,\n", top);
 109         printf("   %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "COUNT");
 110         printa("   %6d %-10s %-48s %@8d\n", @num);
 111
 112         trunc(@types, top);
 113         normalize(@types, 1000);
 114         printf("\nTop %d elapsed times (us),\n", top);
 115         printf("   %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "TOTAL");
 116         printa("   %6d %-10s %-48s %@8d\n", @types);
 117
 118         trunc(@types_excl, top);
 119         normalize(@types_excl, 1000);
 120         printf("\nTop %d exclusive method elapsed times (us),\n", top);
 121         printf("   %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "TOTAL");
 122         printa("   %6d %-10s %-48s %@8d\n", @types_excl);
 123
 124         trunc(@types_incl, top);
 125         normalize(@types_incl, 1000);
 126         printf("\nTop %d inclusive method elapsed times (us),\n", top);
 127         printf("   %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "TOTAL");
 128         printa("   %6d %-10s %-48s %@8d\n", @types_incl);
 129 }