diff options
Diffstat (limited to 'cddl/contrib/dtracetoolkit/Examples/tcl_flowtime_example.txt')
-rw-r--r-- | cddl/contrib/dtracetoolkit/Examples/tcl_flowtime_example.txt | 197 |
1 files changed, 197 insertions, 0 deletions
diff --git a/cddl/contrib/dtracetoolkit/Examples/tcl_flowtime_example.txt b/cddl/contrib/dtracetoolkit/Examples/tcl_flowtime_example.txt new file mode 100644 index 0000000..8e07238 --- /dev/null +++ b/cddl/contrib/dtracetoolkit/Examples/tcl_flowtime_example.txt @@ -0,0 +1,197 @@ +Following are examples of running tcl_flowtime.d. + +Here the tcl_flowtime.d script is running on the program +Code/Tcl/func_abc.tcl. + + +# tcl_flowtime.d + C PID TIME(us) DELTA(us) -- CALL + 0 17901 4436098007906 2 > if + 0 17901 4436098007976 70 > info + 0 17901 4436098007998 21 < info + 0 17901 4436098008050 52 > proc + 0 17901 4436098008063 12 < proc + 0 17901 4436098008069 6 < if + 0 17901 4436098008085 15 > tclInit + 0 17901 4436098008286 201 -> tclInit + 0 17901 4436098008295 8 > global + 0 17901 4436098008305 10 < global + 0 17901 4436098008311 6 > global + 0 17901 4436098008318 6 < global + 0 17901 4436098008323 5 > rename + 0 17901 4436098008342 18 < rename + 0 17901 4436098008353 10 > info + 0 17901 4436098008362 9 < info + 0 17901 4436098008369 6 > info + 0 17901 4436098008395 25 < info + 0 17901 4436098008403 8 > unset + 0 17901 4436098008410 6 < unset + 0 17901 4436098008416 5 > concat + 0 17901 4436098008425 8 < concat + 0 17901 4436098008440 15 > file + 0 17901 4436098008459 18 < file + 0 17901 4436098008465 6 > file + 0 17901 4436098008543 78 < file + 0 17901 4436098008550 7 > file + 0 17901 4436098008560 9 < file + 0 17901 4436098008567 7 > file + 0 17901 4436098008671 104 < file + 0 17901 4436098008678 7 > file + 0 17901 4436098008688 9 < file + 0 17901 4436098008695 6 > file + 0 17901 4436098008780 84 < file + 0 17901 4436098008787 6 > file + 0 17901 4436098008796 9 < file + 0 17901 4436098008803 6 > file + 0 17901 4436098008854 51 < file + 0 17901 4436098008862 7 > uplevel + 0 17901 4436098008872 10 > source + 0 17901 4436098009290 417 > if + 0 17901 4436098009304 14 > info + 0 17901 4436098009311 7 < info + 0 17901 4436098009319 7 < if + 0 17901 4436098009331 11 > package + 0 17901 4436098009340 9 < package + 0 17901 4436098009353 12 > if + 0 17901 4436098009363 10 > info + 0 17901 4436098009369 6 < info + 0 17901 4436098009390 20 > info + 0 17901 4436098009413 22 < info + 0 17901 4436098009421 7 < if + 0 17901 4436098009439 18 > namespace + 0 17901 4436098009530 90 > variable + 0 17901 4436098009537 7 < variable + 0 17901 4436098009544 6 > info + 0 17901 4436098009554 10 < info + 0 17901 4436098009561 6 > info + 0 17901 4436098009567 6 < info + 0 17901 4436098009573 5 > info + 0 17901 4436098009579 6 < info + 0 17901 4436098009586 6 > file + 0 17901 4436098009605 19 < file + 0 17901 4436098009611 6 > list + 0 17901 4436098009627 15 < list + 0 17901 4436098009633 6 > foreach + 0 17901 4436098009658 24 > lsearch + 0 17901 4436098009665 7 < lsearch + 0 17901 4436098009673 7 > lappend + 0 17901 4436098009680 7 < lappend + 0 17901 4436098009689 9 > lsearch + 0 17901 4436098009694 5 < lsearch + 0 17901 4436098009700 6 > lappend + 0 17901 4436098009707 6 < lappend + 0 17901 4436098009712 5 < foreach + 0 17901 4436098009719 6 > info + 0 17901 4436098009726 7 < info + 0 17901 4436098009732 5 > file + 0 17901 4436098009749 17 < file + 0 17901 4436098009756 6 > file + 0 17901 4436098009772 16 < file + 0 17901 4436098009778 6 > file + 0 17901 4436098009787 9 < file + 0 17901 4436098009795 7 > lsearch + 0 17901 4436098009800 5 < lsearch + 0 17901 4436098009806 6 > lappend + 0 17901 4436098009812 5 < lappend + 0 17901 4436098009818 5 > info + 0 17901 4436098009823 5 < info + 0 17901 4436098009830 6 > foreach + 0 17901 4436098009840 9 > lsearch + 0 17901 4436098009845 5 < lsearch + 0 17901 4436098009851 6 > lappend + 0 17901 4436098009857 5 < lappend + 0 17901 4436098009862 5 < foreach + 0 17901 4436098009868 5 < namespace + 0 17901 4436098009896 27 > if + 0 17901 4436098009915 18 > interp + 0 17901 4436098009922 7 < interp + 0 17901 4436098009930 8 < if + 0 17901 4436098009943 12 > package + 0 17901 4436098009949 5 < package + 0 17901 4436098009960 10 > if + 0 17901 4436098009970 10 > interp + 0 17901 4436098009976 5 < interp + 0 17901 4436098010018 41 < if + 0 17901 4436098010036 18 > if + 0 17901 4436098010049 12 > namespace + 0 17901 4436098010057 7 < namespace + 0 17901 4436098010063 6 < if + 0 17901 4436098010074 11 > set + 0 17901 4436098010081 6 < set + 0 17901 4436098010089 8 > set + 0 17901 4436098010095 5 < set + 0 17901 4436098010104 9 > if + 0 17901 4436098010116 12 > namespace + 0 17901 4436098010122 6 < namespace + 0 17901 4436098010133 10 > proc + 0 17901 4436098010142 8 < proc + 0 17901 4436098010148 5 < if + 0 17901 4436098010228 79 > proc + 0 17901 4436098010237 8 < proc + 0 17901 4436098010255 18 > proc + 0 17901 4436098010264 9 < proc + 0 17901 4436098010293 29 > proc + 0 17901 4436098010301 7 < proc + 0 17901 4436098010320 18 > proc + 0 17901 4436098010329 9 < proc + 0 17901 4436098010342 13 > proc + 0 17901 4436098010350 7 < proc + 0 17901 4436098010394 44 > if + 0 17901 4436098010418 23 > proc + 0 17901 4436098010437 18 < proc + 0 17901 4436098010443 6 < if + 0 17901 4436098010563 120 > proc + 0 17901 4436098010575 12 < proc + 0 17901 4436098010582 7 < source + 0 17901 4436098010588 5 < uplevel + 0 17901 4436098010596 8 <- tclInit + 0 17901 4436098010610 13 < tclInit + 0 17901 4436098010800 190 > proc + 0 17901 4436098010809 8 < proc + 0 17901 4436098010818 9 > proc + 0 17901 4436098010825 6 < proc + 0 17901 4436098010833 8 > proc + 0 17901 4436098010840 6 < proc + 0 17901 4436098010847 7 > func_a + 0 17901 4436098010863 15 -> func_a + 0 17901 4436098010870 6 > puts + 0 17901 4436098011006 136 < puts + 0 17901 4436098011014 7 > after + 0 17901 4436099020588 1009573 < after + 0 17901 4436099020611 23 > func_b + 0 17901 4436099020646 34 -> func_b + 0 17901 4436099020655 8 > puts + 0 17901 4436099020697 41 < puts + 0 17901 4436099020703 6 > after + 0 17901 4436100030614 1009910 < after + 0 17901 4436100030638 24 > func_c + 0 17901 4436100030671 32 -> func_c + 0 17901 4436100030680 9 > puts + 0 17901 4436100030723 42 < puts + 0 17901 4436100030729 6 > after + 0 17901 4436101040600 1009870 < after + 0 17901 4436101040623 22 <- func_c + 0 17901 4436101040633 10 < func_c + 0 17901 4436101040639 6 <- func_b + 0 17901 4436101040645 5 < func_b + 0 17901 4436101040651 5 <- func_a + 0 17901 4436101040656 5 < func_a + 0 17901 4436101040682 25 > exit + +You can see the output is in six columns. + +The first column is CPU-id, the second is PID, third is the time since boot in +microseconds, fourth is the elapsed time since the previous action. The fifth +and sixth columns represent the action. The Tcl command or procedure name is +prefixed by an indicator reprenting what is happening. These may be -> +(procedure entry), <- (procedure return), > (command entry), or < (command +return). + +As each action is taken, the fifth and sixth columns are indented by 2 spaces. +This shows which procedure or command is calling which. + +If the output looks shuffled, check the CPU "C" and "TIME" columns, and +post sort based on TIME if necessary. + +See Notes/ALLflow_notes.txt for important notes about reading flow outputs. + |