Tcl Programming/Debugging

Tcl itself is quite a good teacher. Don't be afraid to do something wrong - it will most often deliver a helpful error message. When tclsh is called with no arguments, it starts in an interactive mode and displays a "%" prompt. The user types something in and sees what comes out: either the result or an error message.

Trying isolated test cases interactively, and pasting the command into the editor when satisfied, can greatly reduce debugging time (there is no need to restart the application after every little change - just make sure it's the right one, before restarting.)

A quick tour

Here's a commented session transcript:

% hello
invalid command name "hello"

OK, so we're supposed to type in a command. Although it doesn't look so, here's one:

% hi
     1  hello
    2  hi

Interactive tclsh tries to guess what we mean, and "hi" is the unambiguous prefix of the "history" command, whose results we see here. Another command worth remembering is "info":

% info
wrong # args: should be "info option ?arg arg ...?"

The error message tells us there should be at least one option, and optionally more arguments.

% info option
bad option "option": must be args, body, cmdcount, commands, complete, default,
exists, functions, globals, hostname, level, library, loaded, locals, nameofexecutable,
patchlevel, procs, script, sharedlibextension, tclversion, or vars

Another helpful error: "option" is not an option, but the valid ones are listed. To get information about commands, it makes sense to type the following:

% info commands
tell socket subst lremove open eof tkcon_tcl_gets pwd glob list exec pid echo 
dir auto_load_index time unknown eval lrange tcl_unknown fblocked lsearch gets 
auto_import case lappend proc break dump variable llength tkcon auto_execok return
pkg_mkIndex linsert error bgerror catch clock info split thread_load loadvfs array
if idebug fconfigure concat join lreplace source fcopy global switch which auto_qualify
update tclPkgUnknown close clear cd for auto_load file append format tkcon_puts alias 
what read package set unalias pkg_compareExtension binary namespace scan edit trace seek 
while flush after more vwait uplevel continue foreach lset rename tkcon_gets fileevent 
regexp tkcon_tcl_puts observe_var tclPkgSetup upvar unset encoding expr load regsub history
exit interp puts incr lindex lsort tclLog observe ls less string

Oh my, quite many... How many?

% llength [info commands]
115

Now for a more practical task - let's let Tcl compute the value of Pi.

% expr acos(-1)
3.14159265359

Hm.. can we have that with more precision?

% set tcl_precision 17
17
% expr acos(-1)
3.1415926535897931

Back to the first try, where "hello" was an invalid command. Let's just create a valid one:

% proc hello {} {puts Hi!}

Silently acknowledged. Now testing:

% hello
Hi!

Errors are exceptions

What in Tcl is called error is in fact more like an exception in other languages - you can deliberately raise an error, and also catch errors. Examples:

if {$username eq ""} {error "please specify a user name"}

if [catch {open $filename w} fp] {
   error "$filename is not writable"
}

One reason for errors can be an undefined command name. One can use this playfully, together with catch, as in the following example of a multi-loop break, that terminates the two nested loops when a matrix element is empty:

if [catch {
   foreach row $matrix {
      foreach col $row {
          if {$col eq ""} throw
      }
   }
}] {puts "empty matrix element found"}

The throw command does not exist in normal Tcl, so it throws an error, which is caught by the catch around the outer loop.

The errorInfo variable

This global variable provided by Tcl contains the last error message and the traceback of the last error. Silly example:

% proc foo {} {bar x}
% proc bar {input} {grill$input}
% foo
invalid command name "grillx"

% set errorInfo
invalid command name "grillx"
   while executing
"grill$input"
   (procedure "bar" line 1)
   invoked from within
"bar x"
   (procedure "foo" line 1)
   invoked from within
"foo"

If no error has occurred yet, errorInfo will contain the empty string.

The errorCode variable

In addition, there is the errorCode variable that returns a list of up to three elements:

category (POSIX, ARITH, ...)
abbreviated code for the last error
human-readable error text

Examples:

% open not_existing
couldn't open "not_existing": no such file or directory
% set errorCode
POSIX ENOENT {no such file or directory}

% expr 1/0
divide by zero
% set errorCode
ARITH DIVZERO {divide by zero}

% foo
invalid command name "foo"
% set errorCode
NONE

Tracing procedure calls

For a quick overview how some procedures are called, and when, and what do they return, and when, the trace execution is a valuable tool. Let's take the following factorial function as example:

proc fac x {expr {$x<2? 1 : $x * [fac [incr x -1]]}}

We need to supply a handler that will be called with different numbers of arguments (two on enter, four on leave). Here's a very simple one:

proc tracer args {puts $args}

Now we instruct the interpreter to trace enter and leave of fac:

trace add execution fac {enter leave} tracer

Let's test it with the factorial of 7:

fac 7

which gives, on stdout:

{fac 7} enter
{fac 6} enter
{fac 5} enter
{fac 4} enter
{fac 3} enter
{fac 2} enter
{fac 1} enter
{fac 1} 0 1 leave
{fac 2} 0 2 leave
{fac 3} 0 6 leave
{fac 4} 0 24 leave
{fac 5} 0 120 leave
{fac 6} 0 720 leave
{fac 7} 0 5040 leave

So we can see how recursion goes down to 1, then returns in backward order, stepwise building up the final result. The 0 that comes as second word in "leave" lines is the return status, 0 being TCL_OK.

Stepping through a procedure

To find out how exactly a proc works (and what goes wrong where), you can also register commands to be called before and after a command inside a procedure is called (going down transitively to all called procs). You can use the following step and interact procedures for this:

proc step {name {yesno 1}} {
   set mode [expr {$yesno? "add" : "remove"}]
   trace $mode execution $name {enterstep leavestep} interact
}

proc interact args {
   if {[lindex $args end] eq "leavestep"} {
       puts ==>[lindex $args 2]
       return
   }
   puts -nonewline "$args --"
   while 1 {
       puts -nonewline "> "
       flush stdout
       gets stdin cmd
       if {$cmd eq "c" || $cmd eq ""} break
       catch {uplevel 1 $cmd} res
       if {[string length $res]} {puts $res}
   }
}

#----------------------------Test case, a simple string reverter:
proc sreverse str {
   set res ""
   for {set i [string length $str]} {$i > 0} {} {
       append res [string index $str [incr i -1]]
   }
   set res
}

#-- Turn on stepping for sreverse:
step sreverse
sreverse hello

#-- Turn off stepping (you can also type this command from inside interact):
step sreverse 0
puts [sreverse Goodbye]

The above code gives the following transcript when sourced into a tclsh:

{set res {}} enterstep -->
==>
{for {set i [string length $str]} {$i > 0} {} {
       append res [string index $str [incr i -1]]
   }} enterstep -->
{string length hello} enterstep -->
==>5
{set i 5} enterstep -->
==>5
{incr i -1} enterstep -->
==>4
{string index hello 4} enterstep -->
==>o
{append res o} enterstep -->
==>o
{incr i -1} enterstep -->
==>3
{string index hello 3} enterstep -->
==>l
{append res l} enterstep -->
==>ol
{incr i -1} enterstep -->
==>2
{string index hello 2} enterstep -->
==>l
{append res l} enterstep -->
==>oll
{incr i -1} enterstep -->
==>1
{string index hello 1} enterstep -->
==>e
{append res e} enterstep -->
==>olle
{incr i -1} enterstep -->
==>0
{string index hello 0} enterstep -->
==>h
{append res h} enterstep -->
==>olleh
==>
{set res} enterstep -->
==>olleh
eybdooG

Debugging

The simplest way to inspect why something goes wrong is inserting a puts command before the place where it happens. Say if you want to see the values of variables x and y, just insert

puts x:$x,y:$y

(if the string argument contains no spaces, it needs not be quoted). The output will go to stdout - the console from where you started the script. On Windows or Mac, you might need to add the command

console show

to get the substitute console Tcl creates for you, when no real one is present.

If at some time you want to see details of what your program does, and at others not, you can define and redefine a dputs command that either calls puts or does nothing:

proc d+ {} {proc dputs args {puts $args}}
proc d- {} {proc dputs args {}}
d+ ;# initially, tracing on... turn off with d-

For more debugging comfort, add the proc interact from above to your code, and put a call to interact before the place where the error happens. Some useful things to do at such a debugging prompt:

info level 0    ;# shows how the current proc was called
info level      ;# shows how deep you are in the call stack
uplevel 1 ...   ;# execute the ... command one level up, i.e. in the caller of the current proc
set ::errorInfo ;# display the last error message in detail

Assertions

Checking data for certain conditions is a frequent operation in coding. Absolutely intolerable conditions can just throw an error:

  if {$temperature > 100} {error "ouch... too hot!"}

Where the error occurred is evident from ::errorInfo, which will look a bit clearer (no mention of the error command) if you code

  if {$temperature > 100} {return -code error "ouch... too hot!"}

If you don't need hand-crafted error messages, you can factor such checks out to an assert command:

proc assert condition {
   set s "{$condition}"
   if {![uplevel 1 expr $s]} {
       return -code error "assertion failed: $condition"
   }
}

Use cases look like this:

  assert {$temperature <= 100}

Note that the condition is reverted - as "assert" means roughly "take for granted", the positive case is specified, and the error is raised if it is not satisfied.

Tests for internal conditions (that do not depend on external data) can be used during development, and when the coder is sure they are bullet-proof to always succeed, (s)he can turn them off centrally in one place by defining

proc assert args {}

This way, assertions are compiled to no bytecode at all, and can remain in the source code as a kind of documentation.

If assertions are tested, it only happens at the position where they stand in the code. Using a trace, it is also possible to specify a condition once, and have it tested whenever a variable's value changes:

proc assertt {varName condition} {
   uplevel 1 [list trace var $varName w "assert $condition ;#"]
}

The ";#" at the end of the trace causes the additional arguments name element op, that are appended to the command prefix when a trace fires, to be ignored as a comment.

Testing:

% assertt list {[llength $list]<10}
% set list {1 2 3 4 5 6 7 8}
1 2 3 4 5 6 7 8
% lappend list 9 10
can't set "list": assertion failed: 10<10

The error message isn't as clear as could be, because the [llength $list] is already substituted in it. But I couldn't find an easy solution to that quirk in this breakfast fun project - backslashing the $condition in the assertt code sure didn't help. Better ideas welcome.

To make the assertion condition more readable, we could quote the condition one more time,i.e

 % assertt list {{[llength $list]<10}}
 % set list {1 2 3 4 5 6 7 8}
 1 2 3 4 5 6 7 8
 % lappend list 9 10
 can't set "list": assertion failed: [llength $list]<10
 %

In this case,when trace trigger fires, the argument for assert is {[llength $list]<10}.

In any case, these few lines of code give us a kind of bounds checking - the size of Tcl's data structures is in principle only bounded by the available virtual memory, but runaway loops may be harder to debug, compared to a few assertt calls for suspicious variables:

assertt aString {[string length $aString]<1024}

or

assertt anArray {[array size anArray] < 1024*1024}

Tcllib has a control::assert with more bells and whistles.

A tiny testing framework

Bugs happen. The earlier found, the easier for the coder, so the golden rule "Test early. Test often" should really be applied.

One easy way is adding self-tests to a file of Tcl code. When the file is loaded as part of a library, just the proc definitions are executed. If however you feed this file directly to a tclsh, that fact is detected, and the "e.g." calls are executed. If the result is not the one expected, this is reported on stdout; and in the end, you even get a little statistics.

Here's a file that implements and demonstrates "e.g.":

# PROLOG -- self-test: if this file is sourced at top level:
if {[info exists argv0]&&[file tail [info script]] eq [file tail $argv0]} {
   set Ntest 0; set Nfail 0
   proc e.g. {cmd -> expected} {
       incr ::Ntest
       catch {uplevel 1 $cmd} res
       if {$res ne $expected} {
           puts "$cmd -> $res, expected $expected"
           incr ::Nfail
       }
   }
} else {proc e.g. args {}} ;# does nothing, compiles to nothing

##------------- Your code goes here, with e.g. tests following
proc sum {a b} {expr {$a+$b}}
e.g. {sum 3 4} -> 7

proc mul {a b} {expr {$a*$b}}
e.g. {mul 7 6} -> 42

# testing a deliberate error (this way, it passes):
e.g. {expr 1/0} -> "divide by zero"

## EPILOG -- show statistics:
e.g. {puts "[info script] : tested $::Ntest, failed $::Nfail"} -> ""

Guarded proc

In more complex Tcl software, it may happen that a procedure is defined twice with different body and/or args, causing hard-to-track errors. The Tcl command proc itself doesn't complain if it is called with an existing name. Here is one way to add this functionality. Early in your code, you overload the proc command like this:

 rename proc _proc
 _proc proc {name args body} {
 	set ns [uplevel namespace current]
 	if {[info commands $name]!="" || [info commands ${ns}::$name]!=""} {
 		puts stderr "warning: [info script] redefines $name in $ns"
 	}
 	uplevel [list _proc $name $args $body]
 }

From the time that is sourced, any attempt to override a proc name will be reported to stderr (on Win-wish, it would show on the console in red). You may make it really strict by adding an "exit" after the "puts stderr ...", or throw an error.

Known feature: proc names with wildcards will run into this trap, e.g.

  proc * args {expr [join $args *]*1}

will always lead to a complaint because "*" fits any proc name. Fix (some regsub magic on 'name') left as an exercise.

Windows wish console

While on Unixes, the standard channels stdin, stdout, and stderr are the same as the terminal you started wish from, a Windows wish doesn't typically have these standard channels (and is mostly started with double-click anyway). To help this, a console was added that takes over the standard channels (stderr even coming in red, stdin in blue). The console is normally hidden, but can be brought up with the command

 console show

You can also use the partially documented "console" command. "console eval <script>" evals the given script in the Tcl interpreter that manages the console. The console's text area is actually a text widget created in this interpreter. For example:

       console eval {.console config -font Times}

will change the font of the console to "Times". Since the console is a Tk text widget, you can use all text widget commands and options on it (for example, changing colors, bindings...).

console eval {winfo children .}

tells you more about the console widget: it is a toplevel with children .menu, .console (text), and .sb (scrollbar). You can resize the whole thing with

console eval {wm geometry . $Wx$H+$X+$Y}

where $W and $H are dimensions in character cells (default 80x24), but $X and $Y are in pixels.

And more again: you can even add widgets to the console - try

console eval {pack [button .b -text hello -command {puts hello}]}

The button appears between the text widget and the scroll bar, and looks and does as expected. There is also a way back: the main interpreter is visible in the console interpreter under the name, consoleinterp.

Remote debugging

Here's a simple experiment on how to connect two Tcl processes so that one (call it "debugger") can inspect and control the other ("debuggee"). Both must have an event loop running (which is true when Tk runs, or when started with e.g. vwait forever).

As this goes over a socket connection, the two processes could be on different hosts and operating systems (though I've so far tested only the localhost variety). Use at your own risk, of course... :^)

The "debuggee" contains in my experiments the following code, in addition to its own:

proc remo_server {{port 3456}} {
   set sock [socket -server remo_accept $port]
}
proc remo_accept {socket adr port} {
   fileevent $socket readable [list remo_go $socket]
}
proc remo_go {sock} {
   gets $sock line
   catch {uplevel \#0 $line} res
   puts $sock $res
   if [catch {flush $sock}] {close $sock}
}
remo_server

The "debugger" in this version (remo.tcl) runs only on Windows in a wish, as it needs a console, but you could modify it to avoid these restrictions:

#!/usr/bin/env wish
console show
wm withdraw .
set remo [socket localhost 3456]
fileevent $remo readable "puts \[gets $remo\]"
proc r args {puts $::remo [join $args]; flush $::remo}
puts "remote connection ready - use r to talk"

Now from remo you can call any Tcl command in the "debuggee", where it is executed in global scope, so in particular you can inspect (and modify) global variables. But you could also redefine procs on the fly, or whatever tickles your fancy... Examples from a remo session, showing that the two have different pids, how errors are reported, and that quoting is different from normal (needs more work):

10 % pid
600
11 % r pid
2556
12 % r wm title . "Under remote control"
wrong # args: should be "wm title window ?newTitle?"
13 % r wm title . {"Under remote control"}