1235368Sgnn#!/usr/sbin/dtrace -Zs 2235368Sgnn/* 3235368Sgnn * sh_wasted.d - measure Bourne shell elapsed times for "wasted" commands. 4235368Sgnn * Written for the sh DTrace provider. 5235368Sgnn * 6235368Sgnn * $Id: sh_wasted.d 25 2007-09-12 09:51:58Z brendan $ 7235368Sgnn * 8235368Sgnn * USAGE: sh_wasted.d { -p PID | -c cmd } # hit Ctrl-C to end 9235368Sgnn * 10235368Sgnn * This script measures "wasted" commands - those which are called externally 11235368Sgnn * but are in fact builtins to the shell. Ever seen a script which calls 12235368Sgnn * /usr/bin/echo needlessly? This script measures that cost. 13235368Sgnn * 14235368Sgnn * FIELDS: 15235368Sgnn * FILE Filename of the shell or shellscript 16235368Sgnn * NAME Name of call 17235368Sgnn * TIME Total elapsed time for calls (us) 18235368Sgnn * 19235368Sgnn * IDEA: Mike Shapiro 20235368Sgnn * 21235368Sgnn * Filename and call names are printed if available. 22235368Sgnn * 23235368Sgnn * COPYRIGHT: Copyright (c) 2007 Brendan Gregg. 24235368Sgnn * 25235368Sgnn * CDDL HEADER START 26235368Sgnn * 27235368Sgnn * The contents of this file are subject to the terms of the 28235368Sgnn * Common Development and Distribution License, Version 1.0 only 29235368Sgnn * (the "License"). You may not use this file except in compliance 30235368Sgnn * with the License. 31235368Sgnn * 32235368Sgnn * You can obtain a copy of the license at Docs/cddl1.txt 33235368Sgnn * or http://www.opensolaris.org/os/licensing. 34235368Sgnn * See the License for the specific language governing permissions 35235368Sgnn * and limitations under the License. 36235368Sgnn * 37235368Sgnn * CDDL HEADER END 38235368Sgnn * 39235368Sgnn * 09-Sep-2007 Brendan Gregg Created this. 40235368Sgnn */ 41235368Sgnn 42235368Sgnn#pragma D option quiet 43235368Sgnn 44235368Sgnndtrace:::BEGIN 45235368Sgnn{ 46235368Sgnn isbuiltin["echo"] = 1; 47235368Sgnn isbuiltin["test"] = 1; 48235368Sgnn /* add builtins here */ 49235368Sgnn 50235368Sgnn printf("Tracing... Hit Ctrl-C to end.\n"); 51235368Sgnn self->start = timestamp; 52235368Sgnn} 53235368Sgnn 54235368Sgnnsh$target:::command-entry 55235368Sgnn{ 56235368Sgnn self->command = timestamp; 57235368Sgnn} 58235368Sgnn 59235368Sgnnsh$target:::command-return 60235368Sgnn{ 61235368Sgnn this->elapsed = timestamp - self->command; 62235368Sgnn this->path = copyinstr(arg1); 63235368Sgnn this->cmd = basename(this->path); 64235368Sgnn} 65235368Sgnn 66235368Sgnnsh$target:::command-return 67235368Sgnn/self->command && !isbuiltin[this->cmd]/ 68235368Sgnn{ 69235368Sgnn @types_cmd[basename(copyinstr(arg0)), this->path] = sum(this->elapsed); 70235368Sgnn self->command = 0; 71235368Sgnn} 72235368Sgnn 73235368Sgnnsh$target:::command-return 74235368Sgnn/self->command/ 75235368Sgnn{ 76235368Sgnn @types_wasted[basename(copyinstr(arg0)), this->path] = 77235368Sgnn sum(this->elapsed); 78235368Sgnn self->command = 0; 79235368Sgnn} 80235368Sgnn 81235368Sgnnproc:::exit 82235368Sgnn/pid == $target/ 83235368Sgnn{ 84235368Sgnn exit(0); 85235368Sgnn} 86235368Sgnn 87235368Sgnndtrace:::END 88235368Sgnn{ 89235368Sgnn this->elapsed = (timestamp - self->start) / 1000; 90235368Sgnn printf("Script duration: %d us\n", this->elapsed); 91235368Sgnn 92235368Sgnn normalize(@types_cmd, 1000); 93235368Sgnn printf("\nExternal command elapsed times,\n"); 94235368Sgnn printf(" %-30s %-22s %8s\n", "FILE", "NAME", "TIME(us)"); 95235368Sgnn printa(" %-30s %-22s %@8d\n", @types_cmd); 96235368Sgnn 97235368Sgnn normalize(@types_wasted, 1000); 98235368Sgnn printf("\nWasted command elapsed times,\n"); 99235368Sgnn printf(" %-30s %-22s %8s\n", "FILE", "NAME", "TIME(us)"); 100235368Sgnn printa(" %-30s %-22s %@8d\n", @types_wasted); 101235368Sgnn} 102