[Richard Suchenwirth] 2006-04-11 - Here is an experiment on how to instrument [proc]s so the [time] they consume is kept track of. It consists of a [namespace] ''timing'', into which instrumented procs are [rename]d, and a wrapper is created that does the time book-keeping (see the ''template'').

''[Lars H], 2006-04-15: Warning: renaming into a different namespace will break everything that relies on procs being in a particular namespace, such as [variable].''

Every time an instrumented proc is called, it calls its timing namesake, adds the time in microseconds to the ''timing::t'' array, and returns the namesake's results. (I did not put these procs into the ''timing'' namespace, to prevent conflicts with user procs of the same name...)
----

 namespace eval timing {array set t {}}

 proc timing args {
   set template {
      set t [time {set res [uplevel 1 ::timing::@here@ $args]}]
      lappend ::timing::t(@here@) [lindex $t 0]
      set res
   }
   foreach procname $args {
      rename $procname ::timing::$procname
      proc $procname args [string map [list @here@ $procname] $template]
   }
 }

#-- This produces a string with the results, in sorted order:

 proc timing'get {{name *}} {
   set res ""
   foreach i [lsort [array names ::timing::t $name]] {
      set times $::timing::t($i)
      append res "$i : [llength $times] times, [mean $times] usec\n" 
   }
   set res
 }
#-- For heavy use, better use a looping mean - see [Elegance vs. performance]
 proc mean list {expr ([join $list +])/double([llength $list])}

#-- Now testing (I let them all wait a while so time for certain gets non-zero):
 proc foo       args {after 10; return 42}
 proc unbraced {x y} {after 10; expr $x+$y}
 proc braced   {x y} {after 10; expr {$x+$y}}

 timing foo unbraced braced

 foreach i {1 2 3 4 5 6 7 8 9 10} {foo; unbraced 17 4; braced 17 4}

 puts [timing'get]

#----- which shows on my machine:

 braced : 10 times, 15500.0 usec
 foo : 10 times, 15700.0 usec
 unbraced : 10 times, 15700.0 usec

The examples are of course over-simplified, and their measured times should not be taken too serious :^)
----
[Category Debugging] | [Arts and crafts of Tcl-Tk programming]