DTrace Provider for Bourne Shell [PSARC/2008/008 FastTrack timeout 01/16/2008] - Spec Update

[Alan Hargreaves]

As promised based on Darren's suggestion, I have updated the spec and 
included it below.

Changes
-------
1. The variable-assign probe has been renamed to variable-set.
2. Added the variable-unset probe
3. Corrected a typo in the probe list.

In the light of adding variable-unset, it seems to m e that the name 
variable set is more consistent than variable-assign.

Regards,
Alan.

=========================

The sh provider makes available probes that can be used to observe the
behaviour of bourne shell scripts.

Probes
------

The sh provider makes available the following probes as exports:

builtin-entry   Fires on entry to a shell builtin command.
builtin-return  Fires on return from a shell builtin command.
command-entry   Fires when the shell execs an external command.
command-return  Fires on return from an external command.
function-entry  Fires on entry into a shell function.
function-return Pires on return from a shell function.
line            Fires before commands on a particular line of code are
		executed.
subshell-entry  Fires when the shell forks a subshell.
subshell-return Fires on return from a forked subshell.
script-start    Fires before any commands in a script are executed.
script-done     Fires on script exit.
variable-assign Fires on assignment to a variable.

The use of non-empty module or function names in a sh* probe is
undefined at this time.

Arguments
---------

builtin-entry,
command-entry,
function-entry

	char *	args[0]	Script Name
	char *	args[1]	Builtin/Command/Function Name
	int	args[2]	Line Number
	int	args[3]	# Arguments
	char **	args[4]	Pointer to argument list

builtin-return,
command-return,
function-return

	char *	args[0]	Script Name
	char *	args[1]	Builtin/Command/Function Name
	int	args[2]	Return Value

subshell-entry

	char *	args[0]	Script Name
	pid_t	args[1]	Forked Process ID

subshell-return

	char *	args[0]	Script Name
	int	args[1]	Return Value

line

	char *	args[0]	Script Name
	int	args[1]	Line Number

script-start

	char *	args[0]	Script Name

script-done

	char *	args[0]	Script Name
	int	args[1]	Exit Value

variable-set

	char *	args[0]	Script Name
	char *	args[1]	Variable Name
	char *	args[2]	Value

variable-unset

	char *	args[0] Script Name
	char *	args[1]	Variable Name

Examples
--------

1. Catching a variable assignment

	Say we want to determine which line in the following script has
	an assignment to WatchedVar:

	#!/bin/sh

	# starting script
	WatchedVar=Value
	unset WatchedVar
	# ending script

	We could use the following script

	#!/usr/sbin/dtrace -s

	#pragma D option quiet

	sh$target:::line { self->line = arg1; }
	sh$target:::variable-set /copyinstr(arg1) == "WatchedVar"/ {
	        printf("%d: %s=%s\n", self->line, copyinstr(arg1),
		    copyinstr(arg2))
	}
	sh$target:::variable-unset /copyinstr(arg1) == "WatchedVar"/ {
	        printf("%d: unset %s\n", self->line, copyinstr(arg1)); }


	$ ./watch.d -c ./var.sh
	4: WatchedVar=Value

2. Watching the time spent in functions

	#!/usr/sbin/dtrace -s

	#pragma D option quiet

	sh$target:::function-entry { self->start = vtimestamp }
	sh$target:::function-return {
		@[copyinstr(arg1)] = quantize(vtimestamp - self->start)
	}

	Similar for the other entry/return probes, with the exception
	of subshell as the probe name is unavailable.

3. Wasted time using external functions instead of builtins

	This script is copied from the DTrace toolkit. It's function
	and how it works should be relatively self explanatory.

#!/usr/sbin/dtrace -Zs
/*
  * sh_wasted.d - measure Bourne shell elapsed times for "wasted" commands.
  *               Written for the sh DTrace provider.
  *
  * $Id: sh_wasted.d 25 2007-09-12 09:51:58Z brendan $
  *
  * USAGE: sh_wasted.d { -p PID | -c cmd }       # hit Ctrl-C to end
  *
  * This script measures "wasted" commands - those which are called 
externally
  * but are in fact builtins to the shell. Ever seen a script which calls
  * /usr/bin/echo needlessly? This script measures that cost.
  *
  * FIELDS:
  *              FILE            Filename of the shell or shellscript
  *              NAME            Name of call
  *              TIME            Total elapsed time for calls (us)
  *
  * IDEA: Mike Shapiro
  *
  * Filename and call names are printed if available.
  *
  * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
  *
  * CDDL HEADER START
  *
  *  The contents of this file are subject to the terms of the
  *  Common Development and Distribution License, Version 1.0 only
  *  (the "License").  You may not use this file except in compliance
  *  with the License.
  *
  *  You can obtain a copy of the license at Docs/cddl1.txt
  *  or http://www.opensolaris.org/os/licensing.
  *  See the License for the specific language governing permissions
  *  and limitations under the License.
  *
  * CDDL HEADER END
  *
  * 09-Sep-2007  Brendan Gregg   Created this.
  */

#pragma D option quiet

dtrace:::BEGIN
{
         isbuiltin["echo"] = 1;
         isbuiltin["test"] = 1;
         /* add builtins here */

         printf("Tracing... Hit Ctrl-C to end.\n");
         self->start = timestamp;
}

sh$target:::command-entry
{
         self->command = timestamp;
}

sh$target:::command-return
{
         this->elapsed = timestamp - self->command;
         this->path = copyinstr(arg1);
         this->cmd = basename(this->path);
}

sh$target:::command-return
/self->command && !isbuiltin[this->cmd]/
{
         @types_cmd[basename(copyinstr(arg0)), this->path] = 
sum(this->elapsed);
         self->command = 0;
}

sh$target:::command-return
/self->command/
{
         @types_wasted[basename(copyinstr(arg0)), this->path] =
             sum(this->elapsed);
         self->command = 0;
}

proc:::exit
/pid == $target/
{
         exit(0);
}

dtrace:::END
{
         this->elapsed = (timestamp - self->start) / 1000;
         printf("Script duration: %d us\n", this->elapsed);

         normalize(@types_cmd, 1000);
         printf("\nExternal command elapsed times,\n");
         printf("   %-30s %-22s %8s\n", "FILE", "NAME", "TIME(us)");
         printa("   %-30s %-22s %@8d\n", @types_cmd);

         normalize(@types_wasted, 1000);
         printf("\nWasted command elapsed times,\n");
         printf("   %-30s %-22s %8s\n", "FILE", "NAME", "TIME(us)");
         printa("   %-30s %-22s %@8d\n", @types_wasted);
}


Stability
---------

Element Name    Class           Data Class
------------------------------------------
Provider        Uncommited      Uncommited
Module          Private         Private
Function        Private         Private
Name            Uncommited      Uncommited
Arguments       Uncommited      Uncommited
------------------------------------------



-- 
Alan Hargreaves - http://blogs.sun.com/tpenta
Staff Engineer (Kernel/VOSJEC/Performance)
Systems Technical Support Centre
Sun Microsystems