1The following are examples of running tcl_flow.d. 2 3Here the script is tracing the execution of Code/Tcl/func_abc.tcl 4 5# tcl_flow.d 6 C PID TIME(us) -- CALL 7 0 16068 3904942506169 > if 8 0 16068 3904942506261 > info 9 0 16068 3904942506286 < info 10 0 16068 3904942506350 > proc 11 0 16068 3904942506363 < proc 12 0 16068 3904942506369 < if 13 0 16068 3904942506383 > tclInit 14 0 16068 3904942506605 -> tclInit 15 0 16068 3904942506614 > global 16 0 16068 3904942506626 < global 17 0 16068 3904942506632 > global 18 0 16068 3904942506638 < global 19 0 16068 3904942506643 > rename 20 0 16068 3904942506666 < rename 21 0 16068 3904942506675 > info 22 0 16068 3904942506685 < info 23 0 16068 3904942506694 > info 24 0 16068 3904942506721 < info 25 0 16068 3904942506728 > unset 26 0 16068 3904942506741 < unset 27 0 16068 3904942506746 > concat 28 0 16068 3904942506760 < concat 29 0 16068 3904942506774 > file 30 0 16068 3904942506792 < file 31 0 16068 3904942506797 > file 32 0 16068 3904942506880 < file 33 0 16068 3904942506885 > file 34 0 16068 3904942506895 < file 35 0 16068 3904942506901 > file 36 0 16068 3904942507009 < file 37 0 16068 3904942507015 > file 38 0 16068 3904942507025 < file 39 0 16068 3904942507031 > file 40 0 16068 3904942507118 < file 41 0 16068 3904942507124 > file 42 0 16068 3904942507133 < file 43 0 16068 3904942507139 > file 44 0 16068 3904942507193 < file 45 0 16068 3904942507200 > uplevel 46 0 16068 3904942507209 > source 47 0 16068 3904942507649 > if 48 0 16068 3904942507664 > info 49 0 16068 3904942507673 < info 50 0 16068 3904942507681 < if 51 0 16068 3904942507691 > package 52 0 16068 3904942507700 < package 53 0 16068 3904942507712 > if 54 0 16068 3904942507722 > info 55 0 16068 3904942507728 < info 56 0 16068 3904942507749 > info 57 0 16068 3904942507773 < info 58 0 16068 3904942507780 < if 59 0 16068 3904942507797 > namespace 60 0 16068 3904942507898 > variable 61 0 16068 3904942507905 < variable 62 0 16068 3904942507911 > info 63 0 16068 3904942507923 < info 64 0 16068 3904942507928 > info 65 0 16068 3904942507934 < info 66 0 16068 3904942507939 > info 67 0 16068 3904942507947 < info 68 0 16068 3904942507952 > file 69 0 16068 3904942507971 < file 70 0 16068 3904942507977 > list 71 0 16068 3904942507991 < list 72 0 16068 3904942507996 > foreach 73 0 16068 3904942508020 > lsearch 74 0 16068 3904942508028 < lsearch 75 0 16068 3904942508034 > lappend 76 0 16068 3904942508041 < lappend 77 0 16068 3904942508051 > lsearch 78 0 16068 3904942508056 < lsearch 79 0 16068 3904942508061 > lappend 80 0 16068 3904942508068 < lappend 81 0 16068 3904942508073 < foreach 82 0 16068 3904942508078 > info 83 0 16068 3904942508086 < info 84 0 16068 3904942508090 > file 85 0 16068 3904942508108 < file 86 0 16068 3904942508113 > file 87 0 16068 3904942508129 < file 88 0 16068 3904942508134 > file 89 0 16068 3904942508142 < file 90 0 16068 3904942508148 > lsearch 91 0 16068 3904942508153 < lsearch 92 0 16068 3904942508158 > lappend 93 0 16068 3904942508166 < lappend 94 0 16068 3904942508170 > info 95 0 16068 3904942508176 < info 96 0 16068 3904942508181 > foreach 97 0 16068 3904942508190 > lsearch 98 0 16068 3904942508195 < lsearch 99 0 16068 3904942508200 > lappend 100 0 16068 3904942508206 < lappend 101 0 16068 3904942508211 < foreach 102 0 16068 3904942508217 < namespace 103 0 16068 3904942508243 > if 104 0 16068 3904942508261 > interp 105 0 16068 3904942508276 < interp 106 0 16068 3904942508283 < if 107 0 16068 3904942508296 > package 108 0 16068 3904942508302 < package 109 0 16068 3904942508312 > if 110 0 16068 3904942508322 > interp 111 0 16068 3904942508328 < interp 112 0 16068 3904942508369 < if 113 0 16068 3904942508387 > if 114 0 16068 3904942508398 > namespace 115 0 16068 3904942508406 < namespace 116 0 16068 3904942508412 < if 117 0 16068 3904942508424 > set 118 0 16068 3904942508430 < set 119 0 16068 3904942508437 > set 120 0 16068 3904942508443 < set 121 0 16068 3904942508451 > if 122 0 16068 3904942508463 > namespace 123 0 16068 3904942508469 < namespace 124 0 16068 3904942508479 > proc 125 0 16068 3904942508488 < proc 126 0 16068 3904942508493 < if 127 0 16068 3904942508573 > proc 128 0 16068 3904942508582 < proc 129 0 16068 3904942508599 > proc 130 0 16068 3904942508609 < proc 131 0 16068 3904942508638 > proc 132 0 16068 3904942508645 < proc 133 0 16068 3904942508664 > proc 134 0 16068 3904942508673 < proc 135 0 16068 3904942508686 > proc 136 0 16068 3904942508693 < proc 137 0 16068 3904942508737 > if 138 0 16068 3904942508760 > proc 139 0 16068 3904942508782 < proc 140 0 16068 3904942508788 < if 141 0 16068 3904942508826 > proc 142 0 16068 3904942508837 < proc 143 0 16068 3904942508843 < source 144 0 16068 3904942508848 < uplevel 145 0 16068 3904942508857 <- tclInit 146 0 16068 3904942508871 < tclInit 147 0 16068 3904942509050 > proc 148 0 16068 3904942509059 < proc 149 0 16068 3904942509067 > proc 150 0 16068 3904942509074 < proc 151 0 16068 3904942509081 > proc 152 0 16068 3904942509088 < proc 153 0 16068 3904942509094 > func_a 154 0 16068 3904942509110 -> func_a 155 0 16068 3904942509116 > puts 156 0 16068 3904942509256 < puts 157 0 16068 3904942509262 > after 158 0 16068 3904943510998 < after 159 0 16068 3904943511016 > func_b 160 0 16068 3904943511050 -> func_b 161 0 16068 3904943511058 > puts 162 0 16068 3904943511090 < puts 163 0 16068 3904943511094 > after 164 0 16068 3904944520994 < after 165 0 16068 3904944521013 > func_c 166 0 16068 3904944521043 -> func_c 167 0 16068 3904944521051 > puts 168 0 16068 3904944521092 < puts 169 0 16068 3904944521097 > after 170 0 16068 3904945530993 < after 171 0 16068 3904945531012 <- func_c 172 0 16068 3904945531020 < func_c 173 0 16068 3904945531025 <- func_b 174 0 16068 3904945531029 < func_b 175 0 16068 3904945531034 <- func_a 176 0 16068 3904945531039 < func_a 177 0 16068 3904945531064 > exit 178^C 179 180You can see the output is in five columns. 181 182The first column is CPU-id, the second is PID, third is the time since boot in 183microseconds since the previous action. The fourth and fifth columns 184represent the action happening. The Tcl command or procedure name is prefixed 185by an indicator reprenting what is happening. These may be -> (procedure 186entry), <- (procedure return), > (command entry), or < (command return). 187 188As each action is taken, the fourth and fifth columns are indented by 2 spaces. 189This shows which procedure or command is calling which. 190 191If the output looks shuffled, check the CPU "C" and "TIME" columns, and 192post sort based on TIME if necessary. 193 194See Notes/ALLflow_notes.txt for important notes about reading flow outputs. 195 196