diff options
Diffstat (limited to 'cddl/contrib/dtracetoolkit/Examples/tcl_calldist_example.txt')
| -rw-r--r-- | cddl/contrib/dtracetoolkit/Examples/tcl_calldist_example.txt | 166 |
1 files changed, 166 insertions, 0 deletions
diff --git a/cddl/contrib/dtracetoolkit/Examples/tcl_calldist_example.txt b/cddl/contrib/dtracetoolkit/Examples/tcl_calldist_example.txt new file mode 100644 index 0000000..3388963 --- /dev/null +++ b/cddl/contrib/dtracetoolkit/Examples/tcl_calldist_example.txt @@ -0,0 +1,166 @@ +The following are examples of tcl_calldist.d. + +This script traces the elapsed time of Tcl procedures and commands and +prints a report containing distribution plots per function. Here it traces the +example program, Code/Tcl/func_abc.tcl + +# tcl_calldist.d +Tracing... Hit Ctrl-C to end. +^C + +Top 10 exclusive elapsed times (us), + PID=16033, cmd, namespace + value ------------- Distribution ------------- count + 1 | 0 + 2 |@@@@@@@@@@@@@ 1 + 4 |@@@@@@@@@@@@@ 1 + 8 | 0 + 16 | 0 + 32 | 0 + 64 | 0 + 128 |@@@@@@@@@@@@@ 1 + 256 | 0 + + PID=16033, cmd, puts + value ------------- Distribution ------------- count + 16 | 0 + 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 + 64 | 0 + 128 |@@@@@@@@@@@@@ 1 + 256 | 0 + + PID=16033, cmd, tclInit + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + + PID=16033, proc, func_a + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + + PID=16033, proc, func_b + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + + PID=16033, proc, func_c + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + + PID=16033, cmd, file + value ------------- Distribution ------------- count + 2 | 0 + 4 |@@@@@@@@@@@@@ 4 + 8 |@@@@@@@ 2 + 16 |@@@@@@@ 2 + 32 |@@@ 1 + 64 |@@@@@@@@@@ 3 + 128 | 0 + + PID=16033, cmd, source + value ------------- Distribution ------------- count + 256 | 0 + 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 1024 | 0 + + PID=16033, cmd, if + value ------------- Distribution ------------- count + 8 | 0 + 16 |@@@@@@@@@@@@@@@@@@@@ 4 + 32 |@@@@@@@@@@@@@@@ 3 + 64 | 0 + 128 | 0 + 256 | 0 + 512 |@@@@@ 1 + 1024 | 0 + + PID=16033, cmd, after + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 + 1048576 | 0 + + +Top 10 inclusive elapsed times (us), + PID=16033, cmd, uplevel + value ------------- Distribution ------------- count + 512 | 0 + 1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2048 | 0 + + PID=16033, cmd, tclInit + value ------------- Distribution ------------- count + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + PID=16033, proc, tclInit + value ------------- Distribution ------------- count + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + PID=16033, cmd, func_c + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 1048576 | 0 + + PID=16033, proc, func_c + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 1048576 | 0 + + PID=16033, cmd, func_b + value ------------- Distribution ------------- count + 524288 | 0 + 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2097152 | 0 + + PID=16033, proc, func_b + value ------------- Distribution ------------- count + 524288 | 0 + 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2097152 | 0 + + PID=16033, cmd, after + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 + 1048576 | 0 + + PID=16033, cmd, func_a + value ------------- Distribution ------------- count + 1048576 | 0 + 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4194304 | 0 + + PID=16033, proc, func_a + value ------------- Distribution ------------- count + 1048576 | 0 + 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4194304 | 0 + +The exclusive function elapsed times show that each func_a took between 256 +and 511 microseconds. This time excludes the time spent in any other functions. + +The inclusive elapsed times section shows that each func_a spent +took between 2.1 and 4.2 seconds. This time also includes the time spent in +any other commands or procedures called by func_a. + +These elapsed times are the absolute time from when the function began to +when it completed - which includes off-CPU time due to other system events +such as I/O, scheduling, interrupts, etc. + +Elapsed times are useful for identifying where latencies are. +See Notes/ALLelapsed_notes.txt for more details. Also see +Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a +detailed explanation of exclusive vs inclusive function time. + |
