1 #!/usr/sbin/dtrace -CZs 2 /* 3 * tcl_calltime.d - measure Tcl elapsed times for different types of operation. 4 * Written for the Tcl DTrace provider. 5 * 6 * $Id: tcl_calltime.d,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $ 7 * 8 * USAGE: tcl_calltime.d [top] # hit Ctrl-C to end 9 * eg, 10 * tcl_calltime.d # default, truncate to 10 lines 11 * tcl_calltime.d 25 # truncate each report section to 25 lines 12 * 13 * This traces activity from all Tcl processes on the system with DTrace 14 * provider support (tcl8.4.16). 15 * 16 * FIELDS: 17 * PID Process ID 18 * TYPE Type of call (proc/cmd/total) 19 * NAME Name of call 20 * TOTAL Total elapsed time for calls (us) 21 * 22 * COPYRIGHT: Copyright (c) 2007 Brendan Gregg. 23 * 24 * CDDL HEADER START 25 * 26 * The contents of this file are subject to the terms of the 27 * Common Development and Distribution License, Version 1.0 only 28 * (the "License"). You may not use this file except in compliance 29 * with the License. 30 * 31 * You can obtain a copy of the license at Docs/cddl1.txt 32 * or http://www.opensolaris.org/os/licensing. 33 * See the License for the specific language governing permissions 34 * and limitations under the License. 35 * 36 * CDDL HEADER END 37 * 38 * 09-Sep-2007 Brendan Gregg Created this. 39 */ 40 41 #define TOP 10 /* default output truncation */ 42 #define B_FALSE 0 43 44 #pragma D option quiet 45 #pragma D option defaultargs 46 47 dtrace:::BEGIN 48 { 49 printf("Tracing... Hit Ctrl-C to end.\n"); 50 top = $1 != 0 ? $1 : TOP; 51 } 52 53 tcl*:::proc-entry 54 { 55 self->depth++; 56 self->exclude[self->depth] = 0; 57 self->proc[self->depth] = timestamp; 58 } 59 60 tcl*:::proc-return 61 /self->proc[self->depth]/ 62 { 63 this->elapsed_incl = timestamp - self->proc[self->depth]; 64 this->elapsed_excl = this->elapsed_incl - self->exclude[self->depth]; 65 self->proc[self->depth] = 0; 66 self->exclude[self->depth] = 0; 67 this->name = copyinstr(arg0); 68 69 @num[pid, "proc", this->name] = count(); 70 @num[0, "total", "-"] = count(); 71 @types_incl[pid, "proc", this->name] = sum(this->elapsed_incl); 72 @types_excl[pid, "proc", this->name] = sum(this->elapsed_excl); 73 @types_excl[0, "total", "-"] = sum(this->elapsed_excl); 74 75 self->depth--; 76 self->exclude[self->depth] += this->elapsed_incl; 77 } 78 79 tcl*:::cmd-entry 80 { 81 self->depth++; 82 self->exclude[self->depth] = 0; 83 self->cmd[self->depth] = timestamp; 84 } 85 86 tcl*:::cmd-return 87 /self->cmd[self->depth]/ 88 { 89 this->elapsed_incl = timestamp - self->cmd[self->depth]; 90 this->elapsed_excl = this->elapsed_incl - self->exclude[self->depth]; 91 self->cmd[self->depth] = 0; 92 self->exclude[self->depth] = 0; 93 this->name = copyinstr(arg0); 94 95 @num[pid, "cmd", this->name] = count(); 96 @num[0, "total", "-"] = count(); 97 @types_incl[pid, "cmd", this->name] = sum(this->elapsed_incl); 98 @types_excl[pid, "cmd", this->name] = sum(this->elapsed_excl); 99 @types_excl[0, "total", "-"] = sum(this->elapsed_excl); 100 101 self->depth--; 102 self->exclude[self->depth] += this->elapsed_incl; 103 } 104 105 dtrace:::END 106 { 107 trunc(@num, top); 108 printf("\nTop %d counts,\n", top); 109 printf(" %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "COUNT"); 110 printa(" %6d %-10s %-48s %@8d\n", @num); 111 112 trunc(@types_excl, top); 113 normalize(@types_excl, 1000); 114 printf("\nTop %d exclusive elapsed times (us),\n", top); 115 printf(" %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "TOTAL"); 116 printa(" %6d %-10s %-48s %@8d\n", @types_excl); 117 118 trunc(@types_incl, top); 119 normalize(@types_incl, 1000); 120 printf("\nTop %d inclusive elapsed times (us),\n", top); 121 printf(" %6s %-10s %-48s %8s\n", "PID", "TYPE", "NAME", "TOTAL"); 122 printa(" %6d %-10s %-48s %@8d\n", @types_incl); 123 } 124