Home | History | Annotate | Line # | Download | only in Shell 
      1 #!/usr/sbin/dtrace -Zs
      2 /*
      3  * sh_cputime.d - measure Bourne shell on-CPU times for types of operation.
      4  *                Written for the sh DTrace provider.
      5  *
      6  * $Id: sh_cputime.d,v 1.1.1.1 2015/09/30 22:01:09 christos Exp $
      7  *
      8  * This traces shell activity from all Bourne shells on the system that are
      9  * running with sh provider support.
     10  *
     11  * USAGE: sh_cputime.d 		# hit Ctrl-C to end
     12  *
     13  * FIELDS:
     14  *		FILE		Filename of the shell or shellscript
     15  *		TYPE		Type of call (func/builtin/cmd/total)
     16  *		NAME		Name of call
     17  *		TOTAL		Total on-CPU time for calls (us)
     18  *
     19  * Filename and call names are printed if available.
     20  *
     21  * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
     22  *
     23  * CDDL HEADER START
     24  *
     25  *  The contents of this file are subject to the terms of the
     26  *  Common Development and Distribution License, Version 1.0 only
     27  *  (the "License").  You may not use this file except in compliance
     28  *  with the License.
     29  *
     30  *  You can obtain a copy of the license at Docs/cddl1.txt
     31  *  or http://www.opensolaris.org/os/licensing.
     32  *  See the License for the specific language governing permissions
     33  *  and limitations under the License.
     34  *
     35  * CDDL HEADER END
     36  *
     37  * 09-Sep-2007	Brendan Gregg	Created this.
     38  */
     39 
     40 #pragma D option quiet
     41 
     42 dtrace:::BEGIN
     43 {
     44 	printf("Tracing... Hit Ctrl-C to end.\n");
     45 }
     46 
     47 sh*:::function-entry
     48 {
     49 	self->depth++;
     50 	self->function[self->depth] = vtimestamp;
     51 	self->exclude[self->depth] = 0;
     52 }
     53 
     54 sh*:::function-return
     55 /self->function[self->depth]/
     56 {
     57 	this->oncpu_incl = vtimestamp - self->function[self->depth];
     58 	this->oncpu_excl = this->oncpu_incl - self->exclude[self->depth];
     59 	self->function[self->depth] = 0;
     60 	self->exclude[self->depth] = 0;
     61 	this->file = basename(copyinstr(arg0));
     62 	this->name = copyinstr(arg1);
     63 
     64 	@num[this->file, "func", this->name] = count();
     65 	@num["-", "total", "-"] = count();
     66 	@types_incl[this->file, "func", this->name] = sum(this->oncpu_incl);
     67 	@types_excl[this->file, "func", this->name] = sum(this->oncpu_excl);
     68 	@types_excl["-", "total", "-"] = sum(this->oncpu_excl);
     69 
     70 	self->depth--;
     71 	self->exclude[self->depth] += this->oncpu_incl;
     72 }
     73 
     74 sh*:::builtin-entry
     75 {
     76 	self->builtin = vtimestamp;
     77 }
     78 
     79 sh*:::builtin-return
     80 /self->builtin/
     81 {
     82 	this->oncpu = vtimestamp - self->builtin;
     83 	self->builtin = 0;
     84 	this->file = basename(copyinstr(arg0));
     85 	this->name = copyinstr(arg1);
     86 
     87 	@num[this->file, "builtin", this->name] = count();
     88 	@num["-", "total", "-"] = count();
     89 	@types[this->file, "builtin", this->name] = sum(this->oncpu);
     90 	@types["-", "total", "-"] = sum(this->oncpu);
     91 
     92 	self->exclude[self->depth] += this->oncpu;
     93 }
     94 
     95 sh*:::command-entry
     96 {
     97 	incmd[pid] = basename(copyinstr(arg0));
     98 	depth[pid] = self->depth;
     99 }
    100 
    101 sh*:::command-return
    102 {
    103 	incmd[pid] = 0;
    104 }
    105 
    106 proc:::exec-success
    107 {
    108 	/*
    109 	 * Due to thread timing after fork(), this probe can fire before
    110 	 * sh*:::command-entry has, which means we can't predicate this
    111 	 * exec() away just yet. Store the vtimestamp in case it is needed.
    112 	 */
    113 	self->command = vtimestamp;
    114 }
    115 
    116 proc:::exit
    117 /incmd[ppid] == NULL/
    118 {
    119 	self->command = 0;
    120 }
    121 
    122 proc:::exit
    123 /incmd[ppid] != NULL/
    124 {
    125 	this->oncpu = vtimestamp - self->command;
    126 	self->command = 0;
    127 
    128 	@num[incmd[ppid], "cmd", execname] = count();
    129 	@num["-", "total", "-"] = count();
    130 	@types[incmd[ppid], "cmd", execname] = sum(this->oncpu);
    131 	@types["-", "total", "-"] = sum(this->oncpu);
    132 
    133 	self->exclude[depth[ppid]] += this->oncpu;
    134 	incmd[ppid] = 0;
    135 	depth[ppid] = 0;
    136 }
    137 
    138 dtrace:::END
    139 {
    140 	printf("\nCounts,\n");
    141 	printf("   %-20s %-10s %-32s %8s\n", "FILE", "TYPE", "NAME", "COUNT");
    142 	printa("   %-20s %-10s %-32s %@8d\n", @num);
    143 
    144 	normalize(@types, 1000);
    145 	printf("\nOn-CPU times (us),\n");
    146 	printf("   %-20s %-10s %-32s %8s\n", "FILE", "TYPE", "NAME", "TOTAL");
    147 	printa("   %-20s %-10s %-32s %@8d\n", @types);
    148 
    149 	normalize(@types_excl, 1000);
    150 	printf("\nExclusive function on-CPU times (us),\n");
    151 	printf("   %-20s %-10s %-32s %8s\n", "FILE", "TYPE", "NAME", "TOTAL");
    152 	printa("   %-20s %-10s %-32s %@8d\n", @types_excl);
    153 
    154 	normalize(@types_incl, 1000);
    155 	printf("\nInclusive function on-CPU times (us),\n");
    156 	printf("   %-20s %-10s %-32s %8s\n", "FILE", "TYPE", "NAME", "TOTAL");
    157 	printa("   %-20s %-10s %-32s %@8d\n", @types_incl);
    158 }
    159