cddl/contrib/dtracetoolkit/Tcl/tcl_insflow.d

   1 #!/usr/sbin/dtrace -Zs
   2 /*
   3  * tcl_insflow.d - snoop Tcl execution showing procedure flow and delta times.
   4  *                  Written for the Tcl DTrace provider.
   5  *
   6  * $Id: tcl_insflow.d 63 2007-10-04 04:34:38Z brendan $
   7  *
   8  * This traces activity from all Tcl processes on the system with DTrace
   9  * provider support (tcl8.4.16).
  10  *
  11  * USAGE: tcl_insflow.d         # hit Ctrl-C to end
  12  *
  13  * This watches Tcl method entries and returns, and indents child
  14  * method calls.
  15  *
  16  * FIELDS:
  17  *              C               CPU-id
  18  *              PID             Process ID
  19  *              TIME(us)        Time since boot, us
  20  *              DELTA(us)       Elapsed time from previous line to this line
  21  *              TYPE            Type of call (proc/cmd/inst)
  22  *              CALL            Tcl command or procedure name
  23  *
  24  * LEGEND:
  25  *              proc            procedure
  26  *              cmd             command
  27  *              inst            instruction
  28  *
  29  * WARNING: Watch the first column carefully, it prints the CPU-id. If it
  30  * changes, then it is very likely that the output has been shuffled.
  31  *
  32  * COPYRIGHT: Copyright (c) 2007 Brendan Gregg.
  33  *
  34  * CDDL HEADER START
  35  *
  36  *  The contents of this file are subject to the terms of the
  37  *  Common Development and Distribution License, Version 1.0 only
  38  *  (the "License").  You may not use this file except in compliance
  39  *  with the License.
  40  *
  41  *  You can obtain a copy of the license at Docs/cddl1.txt
  42  *  or http://www.opensolaris.org/os/licensing.
  43  *  See the License for the specific language governing permissions
  44  *  and limitations under the License.
  45  *
  46  * CDDL HEADER END
  47  *
  48  * 09-Sep-2007  Brendan Gregg   Created this.
  49  */
  50
  51 #pragma D option quiet
  52 #pragma D option switchrate=10
  53
  54 self int depth;
  55
  56 dtrace:::BEGIN
  57 {
  58         printf("%3s %6s %-16s %9s %5s -- %s\n", "C", "PID", "TIME(us)",
  59             "DELTA(us)", "TYPE", "CALL");
  60 }
  61
  62 tcl*:::proc-entry,
  63 tcl*:::proc-return,
  64 tcl*:::cmd-entry,
  65 tcl*:::cmd-return
  66 /self->last == 0/
  67 {
  68         self->last = timestamp;
  69 }
  70
  71 tcl*:::proc-entry
  72 {
  73         this->delta = (timestamp - self->last) / 1000;
  74         printf("%3d %6d %-16d %9d %5s %*s-> %s\n", cpu, pid, timestamp / 1000,
  75             this->delta, "proc", self->depth * 2, "", copyinstr(arg0));
  76         self->depth++;
  77         self->last = timestamp;
  78 }
  79
  80 tcl*:::proc-return
  81 {
  82         this->delta = (timestamp - self->last) / 1000;
  83         self->depth -= self->depth > 0 ? 1 : 0;
  84         printf("%3d %6d %-16d %9d %5s %*s<- %s\n", cpu, pid, timestamp / 1000,
  85             this->delta, "proc", self->depth * 2, "", copyinstr(arg0));
  86         self->last = timestamp;
  87 }
  88
  89 tcl*:::cmd-entry
  90 {
  91         this->delta = (timestamp - self->last) / 1000;
  92         printf("%3d %6d %-16d %9d %5s %*s-> %s\n", cpu, pid, timestamp / 1000,
  93             this->delta, "cmd", self->depth * 2, "", copyinstr(arg0));
  94         self->depth++;
  95         self->last = timestamp;
  96 }
  97
  98 tcl*:::cmd-return
  99 {
 100         this->delta = (timestamp - self->last) / 1000;
 101         self->depth -= self->depth > 0 ? 1 : 0;
 102         printf("%3d %6d %-16d %9d %5s %*s<- %s\n", cpu, pid, timestamp / 1000,
 103             this->delta, "cmd", self->depth * 2, "", copyinstr(arg0));
 104         self->last = timestamp;
 105 }
 106
 107 tcl*:::inst-start
 108 {
 109         this->delta = (timestamp - self->last) / 1000;
 110         printf("%3d %6d %-16d %9d %5s %*s-> %s\n", cpu, pid, timestamp / 1000,
 111             this->delta, "inst", self->depth * 2, "", copyinstr(arg0));
 112         self->depth++;
 113         self->last = timestamp;
 114 }
 115
 116 tcl*:::inst-done
 117 {
 118         this->delta = (timestamp - self->last) / 1000;
 119         self->depth -= self->depth > 0 ? 1 : 0;
 120         printf("%3d %6d %-16d %9d %5s %*s<- %s\n", cpu, pid, timestamp / 1000,
 121             this->delta, "inst", self->depth * 2, "", copyinstr(arg0));
 122         self->last = timestamp;
 123 }