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