1The following are examples of tcl_calltime.d. 2 3This script traces the total elapsed time of different Tcl commands and 4procedures and prints a report. Here it traces the example program, 5Code/Tcl/func_abc.tcl 6 7# tcl_calltime.d 8Tracing... Hit Ctrl-C to end. 9^C 10 11Top 10 counts, 12 PID TYPE NAME COUNT 13 16028 cmd after 3 14 16028 cmd namespace 3 15 16028 cmd puts 3 16 16028 cmd lappend 4 17 16028 cmd lsearch 4 18 16028 cmd if 8 19 16028 cmd info 11 20 16028 cmd file 12 21 16028 cmd proc 12 22 0 total - 85 23 24Top 10 exclusive elapsed times (us), 25 PID TYPE NAME TOTAL 26 16028 cmd tclInit 253 27 16028 cmd namespace 272 28 16028 proc func_c 330 29 16028 proc func_b 357 30 16028 proc func_a 363 31 16028 cmd file 416 32 16028 cmd if 852 33 16028 cmd source 929 34 16028 cmd after 3025152 35 0 total - 3030001 36 37Top 10 inclusive elapsed times (us), 38 PID TYPE NAME TOTAL 39 16028 cmd uplevel 1849 40 16028 proc tclInit 2519 41 16028 cmd tclInit 2772 42 16028 proc func_c 1010031 43 16028 cmd func_c 1010088 44 16028 proc func_b 2020059 45 16028 cmd func_b 2020106 46 16028 cmd after 3025152 47 16028 proc func_a 3026545 48 16028 cmd func_a 3026572 49 50The output is in three sections. The first shows the top ten most executed 51commands while the script is tracing. 52 53The second (Top 10 exclusive elapsed times) shows us the top ten slowest 54commands or procedures, this number excludes any subroutines called during 55command execution. 56 57The third (Top 10 inclusive elapsed times) shows us the top ten slowest 58commands or procedures including any time spent in subroutines. You can see 59that func_a took the most amount of time all up. This makes sense if you 60compare the code at Code/Tcl/func_abc.tcl with the results. 61 62