1#!/usr/sbin/dtrace -qs
2/*
3 * shortlived.d - determine time spent by short lived processes.
4 *                Written in DTrace (Solaris 10 3/05).
5 *
6 * $Id: shortlived.d 3 2007-08-01 10:50:08Z brendan $
7 *
8 * USAGE:    shortlived.d	# wait, then hit Ctrl-C
9 *
10 * Applications that run many short lived processes can cause load
11 * on the system that is difficult to identify - the processes
12 * aren't sampled in time by programs such as prstat. This program
13 * illustrates how much time was spent processing those extra
14 * processes, and a table of process name by total times for each.
15 *
16 * SEE ALSO: execsnoop
17 *
18 * Notes:
19 * - The measurements are minimum values, not all of the overheads
20 *   caused by process generation and destruction are measured (DTrace
21 *   can do so, but the script would become seriously complex).
22 * - The summary values are accurate, the by program and by PPID values
23 *   are usually slightly smaller due to rounding errors.
24 *
25 * COPYRIGHT: Copyright (c) 2005, 2006 Brendan Gregg.
26 *
27 * CDDL HEADER START
28 *
29 *  The contents of this file are subject to the terms of the
30 *  Common Development and Distribution License, Version 1.0 only
31 *  (the "License").  You may not use this file except in compliance
32 *  with the License.
33 *
34 *  You can obtain a copy of the license at Docs/cddl1.txt
35 *  or http://www.opensolaris.org/os/licensing.
36 *  See the License for the specific language governing permissions
37 *  and limitations under the License.
38 *
39 * CDDL HEADER END
40 *
41 * 22-Apr-2005  Brendan Gregg   Created this.
42 * 20-Apr-2006	   "      "	Last update.
43 */
44
45/*
46 * Start
47 */
48dtrace:::BEGIN
49{
50	/* save start time */
51	start = timestamp;
52
53	/* this is time spent on shortlived processes */
54	procs = 0;
55
56	/* print header */
57	printf("Tracing... Hit Ctrl-C to stop.\n");
58}
59
60/*
61 * Measure parent fork time
62 */
63syscall::*fork*:entry
64{
65	/* save start of fork */
66	self->fork = vtimestamp;
67}
68syscall::*fork*:return
69/arg0 != 0 && self->fork/
70{
71	/* record elapsed time for the fork syscall */
72	this->elapsed = vtimestamp - self->fork;
73	procs += this->elapsed;
74	self->fork = 0;
75}
76
77/*
78 * Measure child processes time
79 */
80syscall::*fork*:return
81/arg0 == 0/
82{
83	/* save start of child process */
84	self->start = vtimestamp;
85
86	/* memory cleanup */
87	self->fork = 0;
88}
89proc:::exit
90/self->start/
91{
92	/* record elapsed time for process execution */
93	this->elapsed = vtimestamp - self->start;
94	procs += this->elapsed;
95
96	/* sum elapsed by process name and ppid */
97	@Times_exec[execname] = sum(this->elapsed/1000000);
98	@Times_ppid[ppid] = sum(this->elapsed/1000000);
99
100	/* memory cleanup */
101	self->start = 0;
102}
103
104/*
105 * Print report
106 */
107dtrace:::END
108{
109	this->total = timestamp - start;
110	printf("short lived processes: %6d.%03d secs\n",
111	    procs/1000000000, (procs%1000000000)/1000000);
112	printf("total sample duration: %6d.%03d secs\n",
113	    this->total/1000000000, (this->total%1000000000)/1000000);
114	printf("\nTotal time by process name,\n");
115	printa("%18s %@12d ms\n", @Times_exec);
116	printf("\nTotal time by PPID,\n");
117	printa("%18d %@12d ms\n", @Times_ppid);
118}
119