Tcl Source Code

Write traces on ::errorInfo no longer work under 8.5  I
due it seems to the refactoring of Tcl_AddObjErrorInfo,
and specifically the removal of Tcl_ObjSetVar2() from
that call.

The setting of a write trace on ::errorInfo lets a
debugger get control of an error before the stack
unwinds to inspect and modify the state/variables
interactively, ala gdb.

Logged In: YES 
user_id=80530
Originator: NO


Note: this commit led to
(exposure of?) Bug 1773040

Logged In: YES 
user_id=80530

patch committed

new test error-7.0 ought to
keep us compatible enough
for your needs.

Do keep an eye on this, though,
as there's still some desire to
move to "lazy" construction of the
::errorInfo value (1047543).

Logged In: YES 
user_id=190660

Tested and verified. The patch 1397843.patch indeed fixes
the problem, as well as elimnating multiple stack-unwind
firings.  Awesome, and elegant.  Thanks Don.

File Added - 162726: 1397843.patch

Logged In: YES 
user_id=80530

please give this patch
against the HEAD a try.

Logged In: YES 
user_id=190660

Following is a minimal script for testing the write
trace on errorInfo.  On 8.5a3 it should output:

  Failed To Intercepted Error:

While others should output:

  Succeed In Intercept Error: BadProc BadProc BadProc
       namespace

Converting to a tcltest script should be trivial.

#########################################
namespace eval eitest {
  set caught 0
  set cmds {}

  proc EIWrite args {
    variable caught
    variable cmds
    set cmd [info level -1]
    set c1 [lindex $cmd 0]
    lappend cmds $c1
    if {[string match *BadProc $c1]} { set caught 1 }
  }
  trace variable ::errorInfo w [namespace current]::EIWrite

  proc BadProc args {
    set i a
    incr i
  }

  catch {BadProc}
  if {$caught} {
    puts "Succeed In Intercept Error: $cmds"
  } else {
    puts "Failed To Intercepted Error: $cmds"
  }
}

Logged In: YES 
user_id=80530


just a minor correction; on the
HEAD ::errorInfo isn't completely
a "virtual variable" -- it is written
to by Tcl_ResetResult() if the interp
has accumulated a stack trace to write
to it.

I'd expect your write traces on the HEAD
to be firing just one time, after the error
completely unwinds.  The incompatible change
is the HEAD does a single write of the
completed value, while 8.4 does several
appends building up the value a piece at a time.

Logged In: YES 
user_id=190660

Technically your right, errorInfo is now a virtual
variable that doesn't actually change until it is 
looked at (via a read trace).  Semantics aside,
in practice this means that the write trace can never fire
when the virtual value changes.

Logged In: YES 
user_id=80530


Peter, can you provide some
tests for the Tcl test suite
that would test this issue to
your satisfaction?

Logged In: YES 
user_id=80530


Your write traces on ::errorInfo
still work in Tcl 8.5.  There's
no failure to live up to that
documentation promise.  What has
changed is the timing of when the
core writes to the ::errorInfo variable.

The overall aim of the refactor was to reduce
the use of global variables and encourage use
of the extended [catch] and corresponding
Tcl_GetReturnOptions() routine in Tcl 8.5.
The refactoring effort here was really
intended to push global variables
::errorInfo and ::errorCode into "legacy
support" status.

Thanks for the additional details
on notification needs.
It sounds like what you really are
looking for is some notification
from each call to Tcl_LogCommandInfo().
Each T_LCI() call adds one "level"
to the -errorinfo return option.
that is, to the Tcl stack trace.

Perhaps what we really need is a
new callback hook to provide you
this notification as part of Tcl's
official interface?

I'm also still looking into whether
we can just extend the "legacy support"
to include reverting to the old
scheme of multiple appends to ::errorInfo
when a write trace is in place.  Our
limited introspection on variable traces
is making that trickier than expected.

Logged In: YES 
user_id=190660

Multiple errorInfo trace firings don't bother me.
Nor do eliminated duplicates.  But failure
to fire at all when errorInfo changes is a problem as
the [trace] man page defines behavior for write as:

  "For write traces, command is invoked  after
  the variable's value has been changed"

I've done a bit of experimentation on 8.5a3, and
the half-backed approach works well enough for my purpose.
But I suspect that doing TclObjLookupVar() every-time
is less efficient than you had in mind when refactoring?
Perhaps the var lookup could be cached
(maybe hooking into the EstablishErrorInfoTraces() call)?
If so then wouldn't TclCallVarTraces() be efficient enough
as a means of "detecting" write traces?
I really don't know enough about in-core details of
variables to really comment knowledgeably about caching them.

Lastly, the question of how often to trigger: I would think
that at least once per Tcl_AddObjErrorInfo() is probably best.
This allows the trace handler to follow the stack
unwind to perform custom logic.  For example
it could collect [info locals] at each level of the unwind.
If that is too inefficient, then minimally the first
call to Tcl_AddObjErrorInfo() in a stack unwind.
Though how you would detect that it's the first is beyond me,
and its not as powerful.

I would be most happy if this could somehow be solved.
Let me know if I can do or test anything to help out.
Incompatible behavior (numbers of firings) is far less
of an issue for me than lack of firing, because it takes
away one of Tcl's best debugging capability.

Logged In: YES 
user_id=80530


In the Tcl 8.4.12 version of
Tcl_AddObjErrorInfo() (in
Revision 1.75.2.19 of tclBasic.c)
some calls can result in two
separate calls of Tcl_ObjSetVar2()
on ::errorInfo -- the first call
at line 5303, and the second call
at line 5329.

This would trigger your write trace
twice, yes?

Your "half-baked" patch would only 
trigger your write trace once, it
appears to me.

Is that level of incompatibility
also a problem for you?  

I'm not inclined to force variable
write traces to happen when no
variable write is in fact taking
place.  I'm looking into detecting
the presence of write traces, though,
and when present, going ahead and
writing to ::errorInfo .  I need to
examine the consequences.

If you can offer additional detail
on when/ how many write trace triggers
you really need (do you really need
every Tcl_AddObjErrorInfo() call?), it
might help me craft a better solution.

Logged In: YES 
user_id=190660


Adding the following  (half-baked) snippet to the end of
Tcl_AddObjErrorInfo seems to resolve the inconsistency.
Couldn't this, or something similar be considered?
****************************************************
{
  Var *varPtr;
  Var *arrayPtr;

  varPtr = TclObjLookupVar(interp, iPtr->eiVar, NULL,
TCL_GLOBAL_ONLY, "set", /*createPart1*/ 0, /*createPart2*/
0,  &arrayPtr);
  if (varPtr == NULL) return;

  TclCallVarTraces((Interp *)interp, arrayPtr, varPtr,
"errorInfo", NULL, TCL_TRACE_WRITES, /* leaveErrMsg */ 0);
}

Logged In: YES 
user_id=80530


This change is noted in the changes
and ChangeLog.2004 files:

2004-10-05 (reform) errorInfo, errorCode management (porter)
        *** POTENTIAL INCOMPATIBILITY for traces on those
vars ***

2004-10-15  Don Porter  <[email protected]>
...
        Reworked management of the "errorInfo" data of an
interp. That
        information is now primarily stored in a new private
(Tcl_Obj *) field
        of the Interp struct, rather than using a global
variable ::errorInfo
        as the primary storage. The ERR_IN_PROGRESS flag bit
value is no
        longer required to manage the value in its new
location, and is
        removed. Variable traces are established to support
compatibility for
        any code expecting the ::errorInfo variable to hold
the information.

        ***POTENTIAL INCOMPATIBILITY***
        Code that sets traces on the ::errorInfo variable
may notice a
        difference in timing of the firing of those traces.
Code that uses the
        value ERR_IN_PROGRESS.