Tcl · Module 14

The Message, errorInfo, and the Stack Trace

The one-line message tells you what failed. The trace tells you where it was called from — and a wrapper that re-raises carelessly deletes it, turning a five-second diagnosis into an afternoon.

Intermediate17 min readtclerrorInfostack-tracedebuggingcatcherror-handling

Part I · Module 14 · Chapter 14.6 · The Message, errorInfo, and the Stack Trace

When a Tcl command fails you get two different things, and most scripts use only the first. There is the message — one line, in catch's result variable — and there is the trace, the full chain of calls that led to the failure, which Tcl assembles for you in the global variable errorInfo.

The message says what. The trace says where from. For a failure three procedures deep, the second is the one that saves your afternoon.

1. The message is one line; the trace is the path

Three procedures, each calling the next, with the innermost raising:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc parse_value {v} {
    if {![string is double -strict $v]} { error "not a number: '$v'" }
    return [expr {$v * 2}]
}
proc parse_line {line} { return [parse_value [lindex $line 1]] }
proc load {lines} {
    set out {}
    foreach l $lines { lappend out [parse_line $l] }
    return $out
}

set rc [catch {load {{clk 1.5} {data abc}}} msg]
puts "  catch returned : $rc"
puts "  the message    : $msg"
puts "  errorInfo:"
puts $::errorInfo

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  catch returned : 1
  the message    : not a number: 'abc'
  errorInfo:
not a number: 'abc'
    while executing
"error "not a number: '$v'" "
    (procedure "parse_value" line 2)
    invoked from within
"parse_value [lindex $line 1]"
    (procedure "parse_line" line 1)
    invoked from within
"parse_line $l"
    (procedure "load" line 3)
    invoked from within
"load {{clk 1.5} {data abc}}"

The message, not a number: 'abc', is all you had from catch alone. The trace adds everything else: it failed in parse_value at line 2, which was called from parse_line line 1, which was called from load line 3, which was called from the top level.

Read it bottom-up for the call path, top-down for the cause. The first line is always the message; each (procedure "name" line N) is a frame, innermost first; the quoted lines between them are the actual command text that was executing in the frame below.

2. Getting the trace without the global

Reading $::errorInfo works but relies on a global that any other code can overwrite. catch's third argument gives you the same text as part of the options dictionary, scoped to this failure:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

catch {load {{clk 1.5} {data abc}}} msg opts
puts "  -errorinfo identical to ::errorInfo? [expr {[dict get $opts -errorinfo] eq $::errorInfo}]"
puts "  -errorline : [dict get $opts -errorline]"
puts "  -errorcode : [dict get $opts -errorcode]"

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  -errorinfo identical to ::errorInfo? 1
  -errorline : 1
  -errorcode : NONE

String-identical. Prefer [dict get $opts -errorinfo] in anything that will be reused: it cannot be clobbered by an unrelated error in between, and it reads as belonging to the catch above it.

The other two keys round out the picture — -errorline is the line within the innermost script, and -errorcode is the structured classification from 14.5 §7. Remember from 14.4 §6 that all three exist only for errors: check the code before reading them.

3. The stale-errorInfo trap

errorInfo is not cleared on success. It holds whatever the last error left there, forever:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

catch {error "an earlier failure"} m
puts "  after a real error, errorInfo = '[lindex [split $::errorInfo \n] 0]'"
set rc [catch {expr {2+2}} m]
puts "  then a SUCCESS: catch returned $rc, result '$m'"
puts "  errorInfo now  = '[lindex [split $::errorInfo \n] 0]'  <- unchanged, still the old error"

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  after a real error, errorInfo = 'an earlier failure'
  then a SUCCESS: catch returned 0, result '4'
  errorInfo now  = 'an earlier failure'  <- unchanged, still the old error

4. Re-raising: three ways, only two of them honest

This is the heart of the chapter. A wrapper catches an error, wants to add its own context, and re-raises. What happens to the trace depends entirely on how.

The same three-deep failure throughout:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc deep {} { error "the real cause" }
proc middle {} { deep }

The discard

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc wrapper_bad {} {
    if {[catch {middle} msg]} { error "wrapper failed: $msg" }
}
catch {wrapper_bad} m
puts $::errorInfo

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

wrapper failed: the real cause
    while executing
"error "wrapper failed: $msg" "
    (procedure "wrapper_bad" line 2)
    invoked from within
"wrapper_bad"

deep and middle are gone. The trace now claims the error originated in wrapper_bad line 2 — which is true of the error command, and useless about the failure. The real cause survives only because it happened to be interpolated into the message text; had the wrapper written error "wrapper failed" instead, every trace of where it came from would be gone.

This is the bug the registry purpose names: a caught error whose errorInfo is thrown away is a bug you will debug twice.

The faithful re-raise

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc wrapper_good {} {
    set rc [catch {middle} msg opts]
    if {$rc != 0} { return -options $opts $msg }
}
catch {wrapper_good} m
puts $::errorInfo

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

the real cause
    while executing
"error "the real cause" "
    (procedure "deep" line 1)
    invoked from within
"deep "
    (procedure "middle" line 1)
    invoked from within
"middle"
    (procedure "wrapper_good" line 2)
    invoked from within
"wrapper_good"

All four frames. deep, middle, and wrapper_good appended as the error passed back through it. The trace is now a complete history, and the -errorcode came along too.

return -options $opts $msg is the right default for any wrapper that does not need to change the message.

Keeping the trace while adding your own message

error takes a second argument that seeds errorInfo. Pass the saved trace and the chain survives:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc first {s} { return [lindex [split $s "\n"] 0] }

proc wrapper_seed {} {
    if {[catch {middle} msg]} {
        error "wrapper failed: $msg" $::errorInfo
    }
}
catch {wrapper_seed} m
puts "  the message       : $m"
puts "  first trace line  : [first $::errorInfo]"
puts "  do they match?    : [expr {$m eq [first $::errorInfo]}]"

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  the message       : wrapper failed: the real cause
  first trace line  : the real cause
  do they match?    : 0

Watch that last line. The message and the first line of the trace now disagree. The caller is told wrapper failed: the real cause, while the trace begins the real cause. Normally the first line of errorInfo is the message, and a reader — or a log parser — relies on that.

Because the second argument replaces errorInfo wholesale, prepend rather than substitute:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

error "while loading the config: $msg" "while loading the config\n$::errorInfo"

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  the message: while loading the config: the real cause
  errorInfo:
while loading the config
the real cause
    while executing
"error "the real cause" "
    (procedure "deep" line 1)
    invoked from within
"deep "
    (procedure "middle" line 1)
    invoked from within
"middle"
    (procedure "wrapper_prepend" line 2)
    invoked from within
"wrapper_prepend"

Your context is on top, the original cause and its full path are underneath.

The rule: return -options $opts $msg unless you have a reason to reword. If you do reword, pass the saved trace as error's second argument, prepended, never replaced.

5. What happens when nobody catches it

Uncaught, tclsh prints the trace for you and stops:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc deep {} { error "disk full" }
proc middle {} { deep }
puts "before"
middle
puts "after"

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

before

That is the whole of standard output. The trace went to standard error:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

disk full
    while executing
"error "disk full" "
    (procedure "deep" line 1)
    invoked from within
"deep "
    (procedure "middle" line 1)
    invoked from within
"middle"
    (file "u.tcl" line 4)

and the process exited 1. Three consequences worth internalising:

after never printed. An uncaught error ends the script at the point of failure, as 14.1 established.
The trace is on stderr, not stdout. A pipeline that captures only stdout — tclsh run.tcl > log.txt — throws every diagnostic away and leaves you a truncated log with no explanation. Redirect both: > log.txt 2>&1.
The bottom frame is (file "u.tcl" line 4), not a procedure. That is the top-level frame, and it tells you which line of the script file started the call chain.

6. A logger that keeps the trace without drowning you

Full traces in normal output are noise; absent traces when something breaks are worse. Print the message always and the trace on request:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

proc run_step {name body} {
    set rc [catch {uplevel 1 $body} result opts]
    if {$rc == 0} {
        puts "  \[ ok \] $name"
        return 1
    }
    puts "  \[fail\] $name: $result"
    if {[info exists ::env(VERBOSE)]} {
        foreach line [split [dict get $opts -errorinfo] "\n"] {
            puts "         | $line"
        }
    }
    return 0
}

run_step "read the netlist"  { expr {1+1} }
run_step "parse slack"       { middle }
run_step "write the report"  { expr {2+2} }

Normally:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  [ ok ] read the netlist
  [fail] parse slack: slack file truncated
  [ ok ] write the report

With VERBOSE=1 in the environment:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  [ ok ] read the netlist
  [fail] parse slack: slack file truncated
         | slack file truncated
         |     while executing
         | "error "slack file truncated" "
         |     (procedure "deep" line 1)
         |     invoked from within
         | "deep "
         |     (procedure "middle" line 1)
         |     invoked from within
         | "middle "
         |     ("uplevel" body line 1)
         |     invoked from within
         | "uplevel 1 $body"

Three design points in that helper:

It reads [dict get $opts -errorinfo], not the global, so it is safe to call from anywhere and immune to §3.
It only reads the trace inside the rc != 0 branch — again §3.
The | prefix keeps the trace visually distinct from the step lines, so a multi-frame trace in the middle of a long run is still scannable.

Notice the trace ends with ("uplevel" body line 1) and "uplevel 1 $body". The trace faithfully records that the body was run by uplevel inside run_step — your harness appears in the trace, which is correct and occasionally confusing. The frames above it are the ones about your bug.

7. Reading a trace quickly

A practical order of attack when a long trace lands in front of you:

Read line 1. That is the message, and half the time it names the file or value and you are done.
Read the topmost (procedure ... line N). That is where it actually broke.
Read the bottom frame. That is what started it — usually a line in your script file.
Only then read the middle, to find which of several call paths this one was.
Check whether a frame you expected is missing. A trace that jumps from your top-level call straight to a wrapper, with nothing between, usually means something re-raised with a fresh error and the §4 discard has eaten the interesting part.

Step 5 is the one worth practising. When a trace looks suspiciously short for the depth of the code, do not conclude the error was shallow — go and find the wrapper that truncated it and fix it to return -options.

8. Exercises

Exercise 1. In the §1 trace, which procedure actually raised the error, and which line of load started the chain?

Exercise 2. Why prefer [dict get $opts -errorinfo] over $::errorInfo?

Exercise 3. A log line prints $::errorInfo whenever a step finishes. What goes wrong?

Exercise 4. A wrapper does if {[catch {work} m]} { error "step failed: $m" }. What is lost, and what replaces it?

Exercise 5. error "mine: $msg" $::errorInfo keeps the trace. What becomes inconsistent, and how do you fix it?

Exercise 6. A script is run as tclsh run.tcl > log.txt and dies with an empty-looking log. Why, and what is the fix?

Answers.

1. parse_value, at its line 2 — the topmost frame. The chain started at load line 3, the lappend out [parse_line $l] inside the foreach.

2. It is scoped to that one catch rather than being a global any other code can overwrite between the failure and your reading of it, and it reads as belonging to the catch above it.

3. errorInfo is never cleared on success, so a step that succeeded gets the trace of the last error — possibly from much earlier in the run — attached to it. Guard every read with a non-zero catch result.

4. Every frame below the wrapper: the trace is truncated to the error command in the wrapper itself. Replace it with set rc [catch {work} m opts] and return -options $opts $m, which appends the wrapper's frame to the original trace instead of replacing it.

5. The message and the first line of errorInfo disagree, because the second argument replaces the trace wholesale rather than adding to it. Prepend instead: error "mine: $msg" "mine\n$::errorInfo".

6. The trace goes to standard error, which was not redirected, so only the puts output before the failure was captured. Use > log.txt 2>&1. The exit status will also be 1, which is worth checking in any wrapper script.

Remember.

The message is one line; errorInfo is the whole call path. Tcl builds the trace as the error unwinds, one frame per procedure boundary.
Read it bottom-up for the path, top-down for the cause. The first (procedure ... line N) is where it broke; the last frame is what started it.
[dict get $opts -errorinfo] is identical to $::errorInfo and is the safer read.
errorInfo is never cleared on success — read it only when catch returned non-zero, or you will attach an old trace to a working operation.
error "wrapper failed: $msg" deletes the trace below the wrapper. This is the discard to hunt for in a code review.
Re-raise with return -options $opts $msg — it appends the wrapper's frame and keeps -errorcode.
To reword and keep the trace, pass it as error's second argument and prepend: "my context\n$::errorInfo". Replacing it desynchronises the message from the trace.
Uncaught: trace to stderr, exit status 1, nothing after the failure runs. Redirect with 2>&1 or the diagnosis is lost.
A trace too short for the code's depth means a wrapper truncated it.

Where this fits

Part of the Tcl curriculum.