diff options
Diffstat (limited to 'cddl/contrib/dtracetoolkit/Examples/sh_calldist_example.txt')
| -rw-r--r-- | cddl/contrib/dtracetoolkit/Examples/sh_calldist_example.txt | 309 |
1 files changed, 309 insertions, 0 deletions
diff --git a/cddl/contrib/dtracetoolkit/Examples/sh_calldist_example.txt b/cddl/contrib/dtracetoolkit/Examples/sh_calldist_example.txt new file mode 100644 index 000000000000..6c6a01faedb5 --- /dev/null +++ b/cddl/contrib/dtracetoolkit/Examples/sh_calldist_example.txt @@ -0,0 +1,309 @@ +The following are examples of sh_calldist.d. + +This script traces the elapsed time of Bourne shell functions and +prints a report containing distribution plots per function. Here it +traces the example program, Code/Shell/func_abc.sh. + + # sh_calldist.d + Tracing... Hit Ctrl-C to end. + ^C + + Elapsed times (us), + + func_abc.sh, builtin, echo + value ------------- Distribution ------------- count + 8 | 0 + 16 |@@@@@@@@@@@@@ 1 + 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 + 64 | 0 + + func_abc.sh, cmd, sleep + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 + 1048576 | 0 + + Exclusive function elapsed times (us), + + func_abc.sh, func, func_a + value ------------- Distribution ------------- count + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + func_abc.sh, func, func_b + value ------------- Distribution ------------- count + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + func_abc.sh, func, func_c + value ------------- Distribution ------------- count + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + Inclusive function elapsed times (us), + + func_abc.sh, func, func_c + value ------------- Distribution ------------- count + 262144 | 0 + 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 1048576 | 0 + + func_abc.sh, func, func_b + value ------------- Distribution ------------- count + 524288 | 0 + 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2097152 | 0 + + func_abc.sh, func, func_a + value ------------- Distribution ------------- count + 1048576 | 0 + 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4194304 | 0 + +The elapsed times show that the echo builtin takes between 16 and 64 us +to execute. + +The exclusive function elapsed times show that each function spent +between 2 and 4 ms. This exclusive time excludes the time spent in +other functions. + +The inclusive function elapsed times show that func_c() took between 0.5 and +1.0 seconds, func_b() took between 1.0 and 2.1 seconds, and func_a() took +between 2.1 and 4.2 seconds to execute. This inclusive time includes the +time spent in other functions and commands called, and since func_a() +calls func_b() which calls func_c(), and, each function is calling "sleep 1", +these times make sense. + +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. + + + +The following traces the firefox startup script. + +# sh_calldist.d +Tracing... Hit Ctrl-C to end. +^C + +Elapsed times (us), + + run-mozilla.sh, builtin, return + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2 | 0 + + run-mozilla.sh, builtin, shift + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 2 | 0 + + run-mozilla.sh, builtin, break + value ------------- Distribution ------------- count + 1 | 0 + 2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 4 | 0 + + firefox, builtin, break + value ------------- Distribution ------------- count + 2 | 0 + 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 8 | 0 + + run-mozilla.sh, builtin, export + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@@@@@@@ 1 + 2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 + 4 | 0 + + firefox, builtin, export + value ------------- Distribution ------------- count + 1 | 0 + 2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 + 4 |@@@@@@@@@@@@@ 1 + 8 | 0 + + firefox, builtin, : + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 5 + 2 | 0 + 4 |@@@@@@@ 1 + 8 | 0 + + firefox, builtin, pwd + value ------------- Distribution ------------- count + 16 | 0 + 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 64 | 0 + + firefox, builtin, test + value ------------- Distribution ------------- count + 16 | 0 + 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 64 | 0 + + firefox, builtin, cd + value ------------- Distribution ------------- count + 4 | 0 + 8 |@@@@@@@@@@@@@ 1 + 16 |@@@@@@@@@@@@@ 1 + 32 |@@@@@@@@@@@@@ 1 + 64 | 0 + + firefox, builtin, [ + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@ 3 + 2 |@@ 1 + 4 |@@ 1 + 8 |@@@@@@@ 3 + 16 |@@@@@@@@@@@ 5 + 32 |@@@@@@@ 3 + 64 |@@@@ 2 + 128 | 0 + + run-mozilla.sh, builtin, type + value ------------- Distribution ------------- count + 256 | 0 + 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 1024 | 0 + + run-mozilla.sh, builtin, [ + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@@ 4 + 2 |@@@@@@@@@@ 5 + 4 |@@@@ 2 + 8 |@@@@@@ 3 + 16 |@@@@@@@@@@ 5 + 32 | 0 + 64 | 0 + 128 | 0 + 256 | 0 + 512 | 0 + 1024 | 0 + 2048 |@@ 1 + 4096 | 0 + + firefox, builtin, echo + value ------------- Distribution ------------- count + 64 | 0 + 128 |@@@@@@@@@@@@@@@@@@@@ 1 + 256 | 0 + 512 | 0 + 1024 | 0 + 2048 |@@@@@@@@@@@@@@@@@@@@ 1 + 4096 | 0 + + firefox, cmd, /usr/lib/firefox/run-mozilla.sh + value ------------- Distribution ------------- count + 2097152 | 0 + 4194304 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 8388608 | 0 + + run-mozilla.sh, cmd, /usr/lib/firefox/firefox-bin + value ------------- Distribution ------------- count + 2097152 | 0 + 4194304 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 8388608 | 0 + +Exclusive function elapsed times (us), + + run-mozilla.sh, func, moz_test_binary + value ------------- Distribution ------------- count + 16 | 0 + 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 64 | 0 + + firefox, func, moz_spc_verbose_echo + value ------------- Distribution ------------- count + 2 | 0 + 4 |@@@@@@@@@@@@@ 2 + 8 |@@@@@@@@@@@@@ 2 + 16 |@@@@@@@@@@@@@ 2 + 32 | 0 + + firefox, func, moz_pis_startstop_scripts + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + 1024 | 0 + 2048 | 0 + 4096 | 0 + 8192 | 0 + 16384 | 0 + 32768 |@@@@@@@@@@@@@@@@@@@@ 1 + 65536 | 0 + + run-mozilla.sh, func, moz_run_program + value ------------- Distribution ------------- count + 65536 | 0 + 131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 262144 | 0 + +Inclusive function elapsed times (us), + + firefox, func, moz_spc_verbose_echo + value ------------- Distribution ------------- count + 4 | 0 + 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4 + 16 |@@@@@@@@@@@@@ 2 + 32 | 0 + + run-mozilla.sh, func, moz_test_binary + value ------------- Distribution ------------- count + 32 | 0 + 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 128 | 0 + + firefox, func, moz_pis_startstop_scripts + value ------------- Distribution ------------- count + 128 | 0 + 256 |@@@@@@@@@@@@@@@@@@@@ 1 + 512 | 0 + 1024 | 0 + 2048 | 0 + 4096 | 0 + 8192 | 0 + 16384 | 0 + 32768 |@@@@@@@@@@@@@@@@@@@@ 1 + 65536 | 0 + + run-mozilla.sh, func, moz_run_program + value ------------- Distribution ------------- count + 2097152 | 0 + 4194304 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 + 8388608 | 0 + + +As an example of interpreting the output: the inclusive elapsed time for +the "[" (test) builtin, + + firefox, builtin, [ + value ------------- Distribution ------------- count + 0 | 0 + 1 |@@@@@@@ 3 + 2 |@@ 1 + 4 |@@ 1 + 8 |@@@@@@@ 3 + 16 |@@@@@@@@@@@ 5 + 32 |@@@@@@@ 3 + 64 |@@@@ 2 + 128 | 0 + +shows that it was called 17 times (after adding up the counts), 5 of which +took between 16 and 31 microseconds. + |