1235368Sgnn#!/usr/sbin/dtrace -Zs
2235368Sgnn/*
3235368Sgnn * sh_pidcolors.d - Demonstration of deeper DTrace Bourne shell analysis.
4235368Sgnn *                  Written for the sh DTrace provider.
5235368Sgnn *
6235368Sgnn * $Id: sh_pidcolors.d 27 2007-09-13 09:26:01Z brendan $
7235368Sgnn *
8235368Sgnn * USAGE: sh_pidcolors.d { -p PID | -c cmd }	# hit Ctrl-C to end
9235368Sgnn *
10235368Sgnn * This extends sh_syscolors.d by including some "pid" provider tracing
11235368Sgnn * as a starting point for deeper analysis. Currently it adds the probes,
12235368Sgnn *
13235368Sgnn *	pid$target:a.out:e*:entry,
14235368Sgnn *	pid$target:a.out:e*:return
15235368Sgnn *
16235368Sgnn * which means, all functions from the /usr/bin/sh binary that begin with
17235368Sgnn * the letter "e". This adds about 34 probes. Customise it to whichever
18235368Sgnn * parts of /usr/bin/sh or the system libraries you are interested in.
19235368Sgnn *
20235368Sgnn * FIELDS:
21235368Sgnn *		C		CPU-id
22235368Sgnn *		PID		Process ID
23235368Sgnn *		DELTA(us)	Elapsed time from previous line to this line
24235368Sgnn *		FILE		Filename of the shell script
25235368Sgnn *		LINE		Line number of filename
26235368Sgnn *		TYPE		Type of call (func/builtin/cmd/line/shell)
27235368Sgnn *		NAME		Shell function, builtin or command name
28235368Sgnn *
29235368Sgnn * The filename for syscalls may be printed as the shell name, if the
30235368Sgnn * script was invoked using the form "shell filename" rather than running
31235368Sgnn * the script with an interpreter line.
32235368Sgnn *
33235368Sgnn * WARNING: Watch the first column carefully, it prints the CPU-id. If it
34235368Sgnn * changes, then it is very likely that the output has been shuffled.
35235368Sgnn *
36235368Sgnn * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
37235368Sgnn *
38235368Sgnn * CDDL HEADER START
39235368Sgnn *
40235368Sgnn *  The contents of this file are subject to the terms of the
41235368Sgnn *  Common Development and Distribution License, Version 1.0 only
42235368Sgnn *  (the "License").  You may not use this file except in compliance
43235368Sgnn *  with the License.
44235368Sgnn *
45235368Sgnn *  You can obtain a copy of the license at Docs/cddl1.txt
46235368Sgnn *  or http://www.opensolaris.org/os/licensing.
47235368Sgnn *  See the License for the specific language governing permissions
48235368Sgnn *  and limitations under the License.
49235368Sgnn *
50235368Sgnn * CDDL HEADER END
51235368Sgnn *
52235368Sgnn * 09-Sep-2007	Brendan Gregg	Created this.
53235368Sgnn */
54235368Sgnn
55235368Sgnn#pragma D option quiet
56235368Sgnn#pragma D option switchrate=10
57235368Sgnn
58235368Sgnnself int depth;
59235368Sgnn
60235368Sgnndtrace:::BEGIN
61235368Sgnn{
62235368Sgnn        color_shell = "\033[2;35m";		/* violet, faint */
63235368Sgnn        color_line = "\033[1;35m";		/* violet, bold */
64235368Sgnn        color_lib = "\033[2;34m";		/* blue, faint */
65235368Sgnn        color_syscall = "\033[2;32m";		/* green, faint */
66235368Sgnn        color_off = "\033[0m";			/* default */
67235368Sgnn
68235368Sgnn	printf("%s %6s %10s  %16s:%-4s %-8s -- %s\n", "C", "PID", "DELTA(us)",
69235368Sgnn	    "FILE", "LINE", "TYPE", "NAME");
70235368Sgnn}
71235368Sgnn
72235368Sgnnsh$target:::function-entry,
73235368Sgnnsh$target:::function-return,
74235368Sgnnsh$target:::builtin-entry,
75235368Sgnnsh$target:::command-entry,
76235368Sgnnsyscall:::entry,
77235368Sgnnsyscall:::return,
78235368Sgnn/* Customize Here, */
79235368Sgnnpid$target:a.out:e*:entry,
80235368Sgnnpid$target:a.out:e*:return
81235368Sgnn/self->last == 0 && pid == $target/
82235368Sgnn{
83235368Sgnn	self->last = timestamp;
84235368Sgnn}
85235368Sgnn
86235368Sgnnsh$target:::function-entry
87235368Sgnn{
88235368Sgnn	this->delta = (timestamp - self->last) / 1000;
89235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s-> %s%s\n", color_shell,
90235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg2, "func",
91235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
92235368Sgnn	self->depth++;
93235368Sgnn	self->last = timestamp;
94235368Sgnn}
95235368Sgnn
96235368Sgnnsh$target:::function-return
97235368Sgnn{
98235368Sgnn	this->delta = (timestamp - self->last) / 1000;
99235368Sgnn	self->depth -= self->depth > 0 ? 1 : 0;
100235368Sgnn	printf("%s%d %6d %10d  %16s:-    %-8s %*s<- %s%s\n", color_shell,
101235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), "func",
102235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
103235368Sgnn	self->last = timestamp;
104235368Sgnn}
105235368Sgnn
106235368Sgnnsh$target:::builtin-entry
107235368Sgnn{
108235368Sgnn	this->delta = (timestamp - self->last) / 1000;
109235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s-> %s%s\n", color_shell,
110235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg2, "builtin",
111235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
112235368Sgnn	self->depth++;
113235368Sgnn	self->last = timestamp;
114235368Sgnn}
115235368Sgnn
116235368Sgnnsh$target:::builtin-return
117235368Sgnn{
118235368Sgnn	this->delta = (timestamp - self->last) / 1000;
119235368Sgnn	self->depth -= self->depth > 0 ? 1 : 0;
120235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s<- %s%s\n", color_shell,
121235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg2, "builtin",
122235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
123235368Sgnn	self->last = timestamp;
124235368Sgnn}
125235368Sgnn
126235368Sgnnsh$target:::command-entry
127235368Sgnn{
128235368Sgnn	this->delta = (timestamp - self->last) / 1000;
129235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s-> %s%s\n", color_shell,
130235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg2, "cmd",
131235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
132235368Sgnn	self->depth++;
133235368Sgnn	self->last = timestamp;
134235368Sgnn}
135235368Sgnn
136235368Sgnnsh$target:::command-return
137235368Sgnn{
138235368Sgnn	this->delta = (timestamp - self->last) / 1000;
139235368Sgnn	self->depth -= self->depth > 0 ? 1 : 0;
140235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s<- %s%s\n", color_shell,
141235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg2, "cmd",
142235368Sgnn	    self->depth * 2, "", copyinstr(arg1), color_off);
143235368Sgnn	self->last = timestamp;
144235368Sgnn}
145235368Sgnn
146235368Sgnnsh$target:::line
147235368Sgnn{
148235368Sgnn	this->delta = (timestamp - self->last) / 1000;
149235368Sgnn	printf("%s%d %6d %10d  %16s:%-4d %-8s %*s-- %s\n", color_line,
150235368Sgnn	    cpu, pid, this->delta, basename(copyinstr(arg0)), arg1, "line",
151235368Sgnn	    self->depth * 2, "", color_off);
152235368Sgnn	self->last = timestamp;
153235368Sgnn}
154235368Sgnn
155235368Sgnn/* Customise Here, */
156235368Sgnnpid$target:a.out:e*:entry
157235368Sgnn{
158235368Sgnn	this->delta = (timestamp - self->last) / 1000;
159235368Sgnn	printf("%s%d %6d %10d  %16s:-    %-8s %*s-> %s%s\n", color_lib,
160235368Sgnn	    cpu, pid, this->delta, basename(execname), "sh",
161235368Sgnn	    self->depth * 2, "", probefunc, color_off);
162235368Sgnn	self->depth++;
163235368Sgnn	self->last = timestamp;
164235368Sgnn}
165235368Sgnn
166235368Sgnn/* Customise Here, */
167235368Sgnnpid$target:a.out:e*:return
168235368Sgnn{
169235368Sgnn	this->delta = (timestamp - self->last) / 1000;
170235368Sgnn	self->depth -= self->depth > 0 ? 1 : 0;
171235368Sgnn	printf("%s%d %6d %10d  %16s:-    %-8s %*s<- %s%s\n", color_lib,
172235368Sgnn	    cpu, pid, this->delta, basename(execname), "sh",
173235368Sgnn	    self->depth * 2, "", probefunc, color_off);
174235368Sgnn	self->last = timestamp;
175235368Sgnn}
176235368Sgnn
177235368Sgnnsyscall:::entry
178235368Sgnn/pid == $target/
179235368Sgnn{
180235368Sgnn	this->delta = (timestamp - self->last) / 1000;
181235368Sgnn	printf("%s%d %6d %10d  %16s:-    %-8s %*s-> %s%s\n", color_syscall,
182235368Sgnn	    cpu, pid, this->delta, basename(execname), "syscall",
183235368Sgnn	    self->depth * 2, "", probefunc, color_off);
184235368Sgnn	self->depth++;
185235368Sgnn	self->last = timestamp;
186235368Sgnn}
187235368Sgnn
188235368Sgnnsyscall:::return
189235368Sgnn/pid == $target/
190235368Sgnn{
191235368Sgnn	this->delta = (timestamp - self->last) / 1000;
192235368Sgnn	self->depth -= self->depth > 0 ? 1 : 0;
193235368Sgnn	printf("%s%d %6d %10d  %16s:-    %-8s %*s<- %s%s\n", color_syscall,
194235368Sgnn	    cpu, pid, this->delta, basename(execname), "syscall",
195235368Sgnn	    self->depth * 2, "", probefunc, color_off);
196235368Sgnn	self->last = timestamp;
197235368Sgnn}
198235368Sgnn
199235368Sgnnproc:::exit
200235368Sgnn/pid == $target/
201235368Sgnn{
202235368Sgnn	exit(0);
203235368Sgnn}
204