#3341 write trace on ::errorInfo is broken

obsolete: 8.5a3
closed-fixed
5
2006-01-11
2006-01-05
No

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.

Discussion

  • miguel sofer

    miguel sofer - 2006-01-05
    • assigned_to: msofer --> dgp
     
  • Don Porter

    Don Porter - 2006-01-05

    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 <dgp@users.sourceforge.net>
    ...
    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.

     
  • Peter MacDonald

    Peter MacDonald - 2006-01-06

    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);
    }

     
  • Don Porter

    Don Porter - 2006-01-06

    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.

     
  • Peter MacDonald

    Peter MacDonald - 2006-01-06

    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.

     
  • Don Porter

    Don Porter - 2006-01-06

    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.

     
  • Don Porter

    Don Porter - 2006-01-06

    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?

     
  • Peter MacDonald

    Peter MacDonald - 2006-01-06

    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.

     
  • Don Porter

    Don Porter - 2006-01-06

    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.

     
  • Peter MacDonald

    Peter MacDonald - 2006-01-07

    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"
    }
    }

     
  • Don Porter

    Don Porter - 2006-01-09
     
  • Don Porter

    Don Porter - 2006-01-09

    Logged In: YES
    user_id=80530

    please give this patch
    against the HEAD a try.

     
  • Peter MacDonald

    Peter MacDonald - 2006-01-10

    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.

     
  • Don Porter

    Don Porter - 2006-01-11
    • labels: 104254 --> 45. Parsing and Eval
    • status: open --> closed-fixed
     
  • Don Porter

    Don Porter - 2006-01-11

    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).

     
  • Don Porter

    Don Porter - 2007-08-13

    Logged In: YES
    user_id=80530
    Originator: NO

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

     

Get latest updates about Open Source Projects, Conferences and News.

Sign up for the SourceForge newsletter:





No, thanks