Simple proc tracing

Richard Suchenwirth 2004-05-09 — One of the simplest ways to debug a proc is to edit in puts commands at interesting places. When satisfied, one should remove those, else they may do their work at unwelcome times. One simple way to avoid this is the following:

 proc dputs args {puts [join $args]}
 #proc dputs args {}
 ...
 dputs value: $value
 ...

In your script, call dputs wherever needed. With simple removal of the # at the second definition, they will not have any effect (and be optimized out of the bytecode), and by editing a single character (the #) you can turn on or off the dputs functionality.

But another idea I tried today is to "instrument" a proc's body for debugging behavior. Now, parsing a proc body for suitable instrumentation points is hard and bug-prone work, considering the many possibilities. But one place in a proc body is bullet-proof to be executed in any case, namely, its very beginning. To observe how procs are called, info level ?n? gives us a great tool. So the following was easily written:

 proc +trace proc {
    proc $proc [info args $proc] \
        "puts \[info level]:\[info level 0]\n#:\n[info body $proc]"
 }

Every time a proc is called, which has been instrumented by +trace, it reports the whole call line, including its name and arguments (by value). This modification to the proc body happens only in memory (not in the source file), so when next starting the app, the trace is gone. This simple mechanism makes experimenting, expecially with recursion, even easier than it was. To remove a +trace from a proc body is easy too, and harmless when it is accidentally called on a not-instrumented proc, if you just choose a marker comment (#: here) that doesn't appear elsewhere in your code:

 proc -trace proc {
    regsub .+#:\n [info body $proc] "" body
    proc $proc [info args $proc] $body
 }
#-- Testing, with the indispensable GCD example:
 proc gcd {u v} {expr {$u? [gcd [expr $v%$u] $u]: $v}}
 +trace gcd
 puts with:[gcd 360 123]
 -trace gcd
 puts without:[gcd 360 123] 

produces first the traced call history, and then nothing but the result:

 1:gcd 360 123
 2:gcd 123 360
 3:gcd 114 123
 4:gcd 9 114
 5:gcd 6 9
 6:gcd 3 6
 7:gcd 0 3
 with:3
 without:3

Documented feature (=bug :): the code above works only for procs without default arguments. If you want these too, replace the calls to info args in +trace and -trace with just args, and add this one:

 proc args proc {
    set res {}
    foreach a [info args $proc] {
        if [info default $proc $a def] {lappend a $def}
        lappend res $a
    }
    set res
 }
#-- Testing again:
 proc foo {a {b 1}} {expr $a+$b}
 puts args:[args foo]

 args:a {b 1}

See also trace for the new trace execution features - however, my 8.4a2 doesn't have them yet, and just to use that appeared to me more complex than +/-trace...