1Following are examples of running tcl_flowtime.d. 2 3Here the tcl_flowtime.d script is running on the program 4Code/Tcl/func_abc.tcl. 5 6 7# tcl_flowtime.d 8 C PID TIME(us) DELTA(us) -- CALL 9 0 17901 4436098007906 2 > if 10 0 17901 4436098007976 70 > info 11 0 17901 4436098007998 21 < info 12 0 17901 4436098008050 52 > proc 13 0 17901 4436098008063 12 < proc 14 0 17901 4436098008069 6 < if 15 0 17901 4436098008085 15 > tclInit 16 0 17901 4436098008286 201 -> tclInit 17 0 17901 4436098008295 8 > global 18 0 17901 4436098008305 10 < global 19 0 17901 4436098008311 6 > global 20 0 17901 4436098008318 6 < global 21 0 17901 4436098008323 5 > rename 22 0 17901 4436098008342 18 < rename 23 0 17901 4436098008353 10 > info 24 0 17901 4436098008362 9 < info 25 0 17901 4436098008369 6 > info 26 0 17901 4436098008395 25 < info 27 0 17901 4436098008403 8 > unset 28 0 17901 4436098008410 6 < unset 29 0 17901 4436098008416 5 > concat 30 0 17901 4436098008425 8 < concat 31 0 17901 4436098008440 15 > file 32 0 17901 4436098008459 18 < file 33 0 17901 4436098008465 6 > file 34 0 17901 4436098008543 78 < file 35 0 17901 4436098008550 7 > file 36 0 17901 4436098008560 9 < file 37 0 17901 4436098008567 7 > file 38 0 17901 4436098008671 104 < file 39 0 17901 4436098008678 7 > file 40 0 17901 4436098008688 9 < file 41 0 17901 4436098008695 6 > file 42 0 17901 4436098008780 84 < file 43 0 17901 4436098008787 6 > file 44 0 17901 4436098008796 9 < file 45 0 17901 4436098008803 6 > file 46 0 17901 4436098008854 51 < file 47 0 17901 4436098008862 7 > uplevel 48 0 17901 4436098008872 10 > source 49 0 17901 4436098009290 417 > if 50 0 17901 4436098009304 14 > info 51 0 17901 4436098009311 7 < info 52 0 17901 4436098009319 7 < if 53 0 17901 4436098009331 11 > package 54 0 17901 4436098009340 9 < package 55 0 17901 4436098009353 12 > if 56 0 17901 4436098009363 10 > info 57 0 17901 4436098009369 6 < info 58 0 17901 4436098009390 20 > info 59 0 17901 4436098009413 22 < info 60 0 17901 4436098009421 7 < if 61 0 17901 4436098009439 18 > namespace 62 0 17901 4436098009530 90 > variable 63 0 17901 4436098009537 7 < variable 64 0 17901 4436098009544 6 > info 65 0 17901 4436098009554 10 < info 66 0 17901 4436098009561 6 > info 67 0 17901 4436098009567 6 < info 68 0 17901 4436098009573 5 > info 69 0 17901 4436098009579 6 < info 70 0 17901 4436098009586 6 > file 71 0 17901 4436098009605 19 < file 72 0 17901 4436098009611 6 > list 73 0 17901 4436098009627 15 < list 74 0 17901 4436098009633 6 > foreach 75 0 17901 4436098009658 24 > lsearch 76 0 17901 4436098009665 7 < lsearch 77 0 17901 4436098009673 7 > lappend 78 0 17901 4436098009680 7 < lappend 79 0 17901 4436098009689 9 > lsearch 80 0 17901 4436098009694 5 < lsearch 81 0 17901 4436098009700 6 > lappend 82 0 17901 4436098009707 6 < lappend 83 0 17901 4436098009712 5 < foreach 84 0 17901 4436098009719 6 > info 85 0 17901 4436098009726 7 < info 86 0 17901 4436098009732 5 > file 87 0 17901 4436098009749 17 < file 88 0 17901 4436098009756 6 > file 89 0 17901 4436098009772 16 < file 90 0 17901 4436098009778 6 > file 91 0 17901 4436098009787 9 < file 92 0 17901 4436098009795 7 > lsearch 93 0 17901 4436098009800 5 < lsearch 94 0 17901 4436098009806 6 > lappend 95 0 17901 4436098009812 5 < lappend 96 0 17901 4436098009818 5 > info 97 0 17901 4436098009823 5 < info 98 0 17901 4436098009830 6 > foreach 99 0 17901 4436098009840 9 > lsearch 100 0 17901 4436098009845 5 < lsearch 101 0 17901 4436098009851 6 > lappend 102 0 17901 4436098009857 5 < lappend 103 0 17901 4436098009862 5 < foreach 104 0 17901 4436098009868 5 < namespace 105 0 17901 4436098009896 27 > if 106 0 17901 4436098009915 18 > interp 107 0 17901 4436098009922 7 < interp 108 0 17901 4436098009930 8 < if 109 0 17901 4436098009943 12 > package 110 0 17901 4436098009949 5 < package 111 0 17901 4436098009960 10 > if 112 0 17901 4436098009970 10 > interp 113 0 17901 4436098009976 5 < interp 114 0 17901 4436098010018 41 < if 115 0 17901 4436098010036 18 > if 116 0 17901 4436098010049 12 > namespace 117 0 17901 4436098010057 7 < namespace 118 0 17901 4436098010063 6 < if 119 0 17901 4436098010074 11 > set 120 0 17901 4436098010081 6 < set 121 0 17901 4436098010089 8 > set 122 0 17901 4436098010095 5 < set 123 0 17901 4436098010104 9 > if 124 0 17901 4436098010116 12 > namespace 125 0 17901 4436098010122 6 < namespace 126 0 17901 4436098010133 10 > proc 127 0 17901 4436098010142 8 < proc 128 0 17901 4436098010148 5 < if 129 0 17901 4436098010228 79 > proc 130 0 17901 4436098010237 8 < proc 131 0 17901 4436098010255 18 > proc 132 0 17901 4436098010264 9 < proc 133 0 17901 4436098010293 29 > proc 134 0 17901 4436098010301 7 < proc 135 0 17901 4436098010320 18 > proc 136 0 17901 4436098010329 9 < proc 137 0 17901 4436098010342 13 > proc 138 0 17901 4436098010350 7 < proc 139 0 17901 4436098010394 44 > if 140 0 17901 4436098010418 23 > proc 141 0 17901 4436098010437 18 < proc 142 0 17901 4436098010443 6 < if 143 0 17901 4436098010563 120 > proc 144 0 17901 4436098010575 12 < proc 145 0 17901 4436098010582 7 < source 146 0 17901 4436098010588 5 < uplevel 147 0 17901 4436098010596 8 <- tclInit 148 0 17901 4436098010610 13 < tclInit 149 0 17901 4436098010800 190 > proc 150 0 17901 4436098010809 8 < proc 151 0 17901 4436098010818 9 > proc 152 0 17901 4436098010825 6 < proc 153 0 17901 4436098010833 8 > proc 154 0 17901 4436098010840 6 < proc 155 0 17901 4436098010847 7 > func_a 156 0 17901 4436098010863 15 -> func_a 157 0 17901 4436098010870 6 > puts 158 0 17901 4436098011006 136 < puts 159 0 17901 4436098011014 7 > after 160 0 17901 4436099020588 1009573 < after 161 0 17901 4436099020611 23 > func_b 162 0 17901 4436099020646 34 -> func_b 163 0 17901 4436099020655 8 > puts 164 0 17901 4436099020697 41 < puts 165 0 17901 4436099020703 6 > after 166 0 17901 4436100030614 1009910 < after 167 0 17901 4436100030638 24 > func_c 168 0 17901 4436100030671 32 -> func_c 169 0 17901 4436100030680 9 > puts 170 0 17901 4436100030723 42 < puts 171 0 17901 4436100030729 6 > after 172 0 17901 4436101040600 1009870 < after 173 0 17901 4436101040623 22 <- func_c 174 0 17901 4436101040633 10 < func_c 175 0 17901 4436101040639 6 <- func_b 176 0 17901 4436101040645 5 < func_b 177 0 17901 4436101040651 5 <- func_a 178 0 17901 4436101040656 5 < func_a 179 0 17901 4436101040682 25 > exit 180 181You can see the output is in six columns. 182 183The first column is CPU-id, the second is PID, third is the time since boot in 184microseconds, fourth is the elapsed time since the previous action. The fifth 185and sixth columns represent the action. The Tcl command or procedure name is 186prefixed by an indicator reprenting what is happening. These may be -> 187(procedure entry), <- (procedure return), > (command entry), or < (command 188return). 189 190As each action is taken, the fifth and sixth columns are indented by 2 spaces. 191This shows which procedure or command is calling which. 192 193If the output looks shuffled, check the CPU "C" and "TIME" columns, and 194post sort based on TIME if necessary. 195 196See Notes/ALLflow_notes.txt for important notes about reading flow outputs. 197 198