1*e137d3e0Schristos #!/usr/sbin/dtrace -Zs
2*e137d3e0Schristos /*
3*e137d3e0Schristos  * j_flowtime.d - snoop Java execution with method flow and delta times.
4*e137d3e0Schristos  *                Written for the Java hotspot DTrace provider.
5*e137d3e0Schristos  *
6*e137d3e0Schristos  * $Id: j_flowtime.d,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $
7*e137d3e0Schristos  *
8*e137d3e0Schristos  * This traces activity from all Java processes on the system with hotspot
9*e137d3e0Schristos  * provider support (1.6.0) and the flag "+ExtendedDTraceProbes". eg,
10*e137d3e0Schristos  * java -XX:+ExtendedDTraceProbes classfile
11*e137d3e0Schristos  *
12*e137d3e0Schristos  * USAGE: j_flowtime.d		# hit Ctrl-C to end
13*e137d3e0Schristos  *
14*e137d3e0Schristos  * This watches Java method entries and returns, and indents child
15*e137d3e0Schristos  * method calls.
16*e137d3e0Schristos  *
17*e137d3e0Schristos  * FIELDS:
18*e137d3e0Schristos  *		C		CPU-id
19*e137d3e0Schristos  *		PID		Process ID
20*e137d3e0Schristos  *		TID		Thread ID
21*e137d3e0Schristos  *		TIME(us)	Time since boot (us)
22*e137d3e0Schristos  *		DELTA(us)	Elapsed time from previous line to this line
23*e137d3e0Schristos  *		CLASS.METHOD	Java class and method name
24*e137d3e0Schristos  *
25*e137d3e0Schristos  * LEGEND:
26*e137d3e0Schristos  *		->		method entry
27*e137d3e0Schristos  *		<-		method return
28*e137d3e0Schristos  *
29*e137d3e0Schristos  * WARNING: Watch the first column carefully, it prints the CPU-id. If it
30*e137d3e0Schristos  * changes, then it is very likely that the output has been shuffled.
31*e137d3e0Schristos  * Changes in TID will appear to shuffle output, as we change from one thread
32*e137d3e0Schristos  * depth to the next. See Docs/Notes/ALLjavaflow.txt for additional notes.
33*e137d3e0Schristos  *
34*e137d3e0Schristos  * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
35*e137d3e0Schristos  *
36*e137d3e0Schristos  * CDDL HEADER START
37*e137d3e0Schristos  *
38*e137d3e0Schristos  *  The contents of this file are subject to the terms of the
39*e137d3e0Schristos  *  Common Development and Distribution License, Version 1.0 only
40*e137d3e0Schristos  *  (the "License").  You may not use this file except in compliance
41*e137d3e0Schristos  *  with the License.
42*e137d3e0Schristos  *
43*e137d3e0Schristos  *  You can obtain a copy of the license at Docs/cddl1.txt
44*e137d3e0Schristos  *  or http://www.opensolaris.org/os/licensing.
45*e137d3e0Schristos  *  See the License for the specific language governing permissions
46*e137d3e0Schristos  *  and limitations under the License.
47*e137d3e0Schristos  *
48*e137d3e0Schristos  * CDDL HEADER END
49*e137d3e0Schristos  *
50*e137d3e0Schristos  * 09-Sep-2007	Brendan Gregg	Created this.
51*e137d3e0Schristos  */
52*e137d3e0Schristos 
53*e137d3e0Schristos /* increasing bufsize can reduce drops */
54*e137d3e0Schristos #pragma D option bufsize=16m
55*e137d3e0Schristos #pragma D option quiet
56*e137d3e0Schristos #pragma D option switchrate=10
57*e137d3e0Schristos 
58*e137d3e0Schristos self int depth[int];
59*e137d3e0Schristos 
60*e137d3e0Schristos dtrace:::BEGIN
61*e137d3e0Schristos {
62*e137d3e0Schristos 	printf("%3s %6s/%-5s %-16s %9s -- %s\n", "C", "PID", "TID", "TIME(us)",
63*e137d3e0Schristos 	    "DELTA(us)", "CLASS.METHOD");
64*e137d3e0Schristos }
65*e137d3e0Schristos 
66*e137d3e0Schristos hotspot*:::method-entry,
67*e137d3e0Schristos hotspot*:::method-return
68*e137d3e0Schristos /self->last == 0/
69*e137d3e0Schristos {
70*e137d3e0Schristos 	self->last = timestamp;
71*e137d3e0Schristos }
72*e137d3e0Schristos 
73*e137d3e0Schristos hotspot*:::method-entry
74*e137d3e0Schristos {
75*e137d3e0Schristos 	this->delta = (timestamp - self->last) / 1000;
76*e137d3e0Schristos 	this->class = (char *)copyin(arg1, arg2 + 1);
77*e137d3e0Schristos 	this->class[arg2] = '\0';
78*e137d3e0Schristos 	this->method = (char *)copyin(arg3, arg4 + 1);
79*e137d3e0Schristos 	this->method[arg4] = '\0';
80*e137d3e0Schristos 
81*e137d3e0Schristos 	printf("%3d %6d/%-5d %-16d %9d %*s-> %s.%s\n", cpu, pid, tid,
82*e137d3e0Schristos 	    timestamp / 1000, this->delta, self->depth[arg0] * 2, "",
83*e137d3e0Schristos 	    stringof(this->class), stringof(this->method));
84*e137d3e0Schristos 	self->depth[arg0]++;
85*e137d3e0Schristos 	self->last = timestamp;
86*e137d3e0Schristos }
87*e137d3e0Schristos 
88*e137d3e0Schristos hotspot*:::method-return
89*e137d3e0Schristos {
90*e137d3e0Schristos 	this->delta = (timestamp - self->last) / 1000;
91*e137d3e0Schristos 	this->class = (char *)copyin(arg1, arg2 + 1);
92*e137d3e0Schristos 	this->class[arg2] = '\0';
93*e137d3e0Schristos 	this->method = (char *)copyin(arg3, arg4 + 1);
94*e137d3e0Schristos 	this->method[arg4] = '\0';
95*e137d3e0Schristos 
96*e137d3e0Schristos 	self->depth[arg0] -= self->depth[arg0] > 0 ? 1 : 0;
97*e137d3e0Schristos 	printf("%3d %6d/%-5d %-16d %9d %*s<- %s.%s\n", cpu, pid, tid,
98*e137d3e0Schristos 	    timestamp / 1000, this->delta, self->depth[arg0] * 2, "",
99*e137d3e0Schristos 	    stringof(this->class), stringof(this->method));
100*e137d3e0Schristos 	self->last = timestamp;
101*e137d3e0Schristos }
102