wish859 segfaults on variable trace
Harald Oehlmann
I would appreciate to get some help for a wish859 crash.
Below is a lot of technical information.
Summary:
Wish crashes with an Access Violation when a variable write trace is
set on errorInfo.
It does not crash without the trace but fails with a script error
(which is ok).
I would like to find the reason for this.
May anybody guide me what to do ?
---
- wish8.5.9 on windows vista 32 bit vc6++ compiler with win 2000 SP1
server platform sdk
- traceback code from http://wiki.tcl.tk/2626
set ::errorLevel -1
set ::errorStack {}
trace add variable ::errorInfo write {
set __n [ info level ]
if {![regexp {\n invoked from within\n} $::errorInfo]} {
set ::errorLevel -1;
set ::errorStack [list];
}
if { ( $__n > 0 ) && ( $__n != $::errorLevel ) } {
set ::errorLevel $__n
set __l [info level 0]
lappend ::errorStack $__l
}
list }
- An error arises and wish closes with an APPCRASH
Error module name: StackHash_fd00
Exception code: c0000005
Exception offset: 7309090a
OS version: 6.0.6002.2.2.0.256.6
Info 1: fd00
Info 2: ea6f5fe8924aaa756324d57f87834160
Info 3: fd00
Info 4: ea6f5fe8924aaa756324d57f87834160
- when I disable the traceback code, wish does not crash and I get the
errorInfo:
> can't use empty string as operand of "/"
> while executing
> "expr {[dict get $dParams Out]/3}"
> (procedure "inkjetoutConfigGet" line 22)
> invoked from within
> "inkjetoutConfigGet"
> ("eval" body line 1)
> invoked from within
> "eval $GetCMD"
> (procedure "ConfigPageCreate" line 8)
> invoked from within
> "ConfigPageCreate $Module config $PFrameScrolled PropEntry ${Module}ConfigGet"
> (procedure "guiConfigShow" line 48)
> invoked from within
> "guiConfigShow [list inkjetout $lVars]"
> (procedure "inkjetoutWizard" line 9)
> invoked from within
> "inkjetoutWizard 1"
> (menu invoke)
- Here is the TCL Code causing the issue:
set CountCur [expr {[dict get $dParams $IndexCur]/3}]
- debugger shows, that the crash happens in the registered callback of
"generic\tclObj.c: getStringFromObj:
(*objPtr->typePtr->updateStringProc)(objPtr);
- Call Stack from VC6 debugger:
7309090a()
Tcl_GetStringFromObj(Tcl_Obj * 0x01f070d8, int * 0x0026ae10) line 1629
+ 15 bytes
Tcl_ListObjGetElements(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x01f070d8,
int * 0x0026ae48, Tcl_Obj * * * 0x0026ae44) line 439 + 42 bytes
Tcl_SetReturnOptions(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x01f070d8)
line 1520 + 66 bytes
TclExecuteByteCode(Tcl_Interp * 0x01bd1af0, ByteCode * 0x03c23df8)
line 2008 + 15 bytes
TclObjInterpProcCore(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03cd9a08,
int 1, void (Tcl_Interp *, Tcl_Obj *)* 0x100fa94d
MakeProcError(Tcl_Interp *, Tcl_Obj *)) line 1760 + 13 bytes
TclObjInterpProc(void * 0x03bebf40, Tcl_Interp * 0x01bd1af0, int 1,
Tcl_Obj * const * 0x01f06ed8) line 1654 + 22 bytes
InvokeImportedCmd(void * 0x03c619a8, Tcl_Interp * 0x01bd1af0, int 1,
Tcl_Obj * const * 0x01f06ed8) line 1890 + 27 bytes
TclEvalObjvInternal(Tcl_Interp * 0x01bd1af0, int 1, Tcl_Obj * const *
0x01f06ed8, const char * 0x03d69870, int 18, int 0) line 3689 + 27
bytes
TclEvalEx(Tcl_Interp * 0x01bd1af0, const char * 0x03d69870, int 18,
int 262144, int 1, int * 0x00000000, const char * 0x03d69870) line
4387 + 33 bytes
Tcl_EvalEx(Tcl_Interp * 0x01bd1af0, const char * 0x03d69870, int 18,
int 262144) line 4043 + 29 bytes
TclEvalObjEx(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03cd8910, int
262144, const CmdFrame * 0x01f06cc4, int 1) line 5217 + 21 bytes
Tcl_EvalObjCmd(void * 0x00000000, Tcl_Interp * 0x01bd1af0, int 2,
Tcl_Obj * const * 0x01f06cec) line 667 + 29 bytes
TclEvalObjvInternal(Tcl_Interp * 0x01bd1af0, int 2, Tcl_Obj * const *
0x01f06cec, const char * 0xffffffff, int -1, int 0) line 3689 + 27
bytes
TclExecuteByteCode(Tcl_Interp * 0x01bd1af0, ByteCode * 0x03da1fa0)
line 2420 + 29 bytes
TclObjInterpProcCore(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03ccfd48,
int 1, void (Tcl_Interp *, Tcl_Obj *)* 0x100fa94d
MakeProcError(Tcl_Interp *, Tcl_Obj *)) line 1760 + 13 bytes
TclObjInterpProc(void * 0x037f17a8, Tcl_Interp * 0x01bd1af0, int 6,
Tcl_Obj * const * 0x01f06bcc) line 1654 + 22 bytes
TclEvalObjvInternal(Tcl_Interp * 0x01bd1af0, int 6, Tcl_Obj * const *
0x01f06bcc, const char * 0xffffffff, int -1, int 0) line 3689 + 27
bytes
TclExecuteByteCode(Tcl_Interp * 0x01bd1af0, ByteCode * 0x022cec38)
line 2420 + 29 bytes
TclObjInterpProcCore(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03ba73c8,
int 1, void (Tcl_Interp *, Tcl_Obj *)* 0x100fa94d
MakeProcError(Tcl_Interp *, Tcl_Obj *)) line 1760 + 13 bytes
TclObjInterpProc(void * 0x037f15f0, Tcl_Interp * 0x01bd1af0, int 2,
Tcl_Obj * const * 0x01f06a94) line 1654 + 22 bytes
InvokeImportedCmd(void * 0x0379f170, Tcl_Interp * 0x01bd1af0, int 2,
Tcl_Obj * const * 0x01f06a94) line 1890 + 27 bytes
TclEvalObjvInternal(Tcl_Interp * 0x01bd1af0, int 2, Tcl_Obj * const *
0x01f06a94, const char * 0xffffffff, int -1, int 0) line 3689 + 27
bytes
TclExecuteByteCode(Tcl_Interp * 0x01bd1af0, ByteCode * 0x039a4600)
line 2420 + 29 bytes
TclObjInterpProcCore(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03ccd4b0,
int 1, void (Tcl_Interp *, Tcl_Obj *)* 0x100fa94d
MakeProcError(Tcl_Interp *, Tcl_Obj *)) line 1760 + 13 bytes
TclObjInterpProc(void * 0x03bea890, Tcl_Interp * 0x01bd1af0, int 2,
Tcl_Obj * const * 0x03b6cae0) line 1654 + 22 bytes
InvokeImportedCmd(void * 0x03c617b0, Tcl_Interp * 0x01bd1af0, int 2,
Tcl_Obj * const * 0x03b6cae0) line 1890 + 27 bytes
TclEvalObjvInternal(Tcl_Interp * 0x01bd1af0, int 2, Tcl_Obj * const *
0x03b6cae0, const char * 0x00000000, int 0, int 131072) line 3689 + 27
bytes
Tcl_EvalObjv(Tcl_Interp * 0x01bd1af0, int 2, Tcl_Obj * const *
0x03b6cae0, int 131072) line 3885 + 25 bytes
TclEvalObjEx(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03ccd438, int
131072, const CmdFrame * 0x00000000, int 0) line 5116 + 21 bytes
Tcl_EvalObjEx(Tcl_Interp * 0x01bd1af0, Tcl_Obj * 0x03ccd438, int
131072) line 5035 + 21 bytes
TkInvokeMenu(Tcl_Interp * 0x01bd1af0, TkMenu * 0x03c22200, int 3) line
1106 + 29 bytes
TkWinHandleMenuEvent(HWND__ * * 0x0026fb44, unsigned int * 0x0026fb48,
unsigned int * 0x0026fb4c, long * 0x0026fb50, long * 0x0026fb38) line
1131 + 23 bytes
TkWinMenuProc(HWND__ * 0x00310380, unsigned int 273, unsigned int 148,
long 0) line 897 + 25 bytes
USER32! 762ffd72()
USER32! 762ffe4a()
USER32! 7630018d()
USER32! 762f8b7c()
Tcl_WaitForEvent(Tcl_Time * 0x01d77d20) line 512 + 12 bytes
Tcl_DoOneEvent(int -3) line 959 + 9 bytes
Tk_MainLoop() line 2141 + 15 bytes
Tk_MainEx(int -1, char * * 0x01d717c0, int (Tcl_Interp *)* 0x00401005
_Tcl_AppInit, Tcl_Interp * 0x01bd1af0) line 314
WinMain(HINSTANCE__ * 0x00400000, HINSTANCE__ * 0x00000000, char *
0x00293523, int 10) line 132 + 37 bytes
WinMainCRTStartup() line 330 + 54 bytes
KERNEL32! 7595d0e9()
NTDLL! 771019bb()
NTDLL! 7710198e()
- The top item of the callstack points to undefined code. The debugger
only shows question marks.
- The second item is row 1629 in tclObj.c. The parameters are:
objPtr:
- refCount: 31551509
- bytes: 0 pointer
- length: 2
- typePtr: many addresses.
The high ref count may indicate a wrong pointer.
- Next level: tclListObj.c Line 439 -> listptr with very high ref
count, only interp pointer makes sense.
- Next: tclResult.c line 1511: Tcl_SetReturnOptions() where the
options object is faulty
- Next: tclExecute.c Line 2008: TclExecuteByteCode
result = Tcl_SetReturnOptions(interp, OBJ_AT_TOS);
Most variables look reasonable, tosPtr contains the issue value.
Harald Oehlmann
-crash.tcl-
console show
set ::errorLevel -1
set ::errorStack {}
trace add variable ::errorInfo write {
set __n [ info level ]
if {![regexp {\n invoked from within\n} $::errorInfo]} {
set ::errorLevel -1;
set ::errorStack [list];
}
if { ( $__n > 0 ) && ( $__n != $::errorLevel ) } {
set ::errorLevel $__n
set __l [info level 0]
lappend ::errorStack $__l
}
list }
namespace eval ns {
set Const(dCommands) [dict create\
01 [dict create In {}]\
]
}
proc ns::nsConfigGet {} {
variable Const
dict for {Command dParams} $Const(dCommands) {
foreach IndexCur {In} {
set CountCur [expr {[dict get $dParams In]/3}]
}
}
}
ns::nsConfigGet
-EOF-
Harald Oehlmann
Gerald W. Lester
Problem does not occur with 8.6.b1.2.
--
+------------------------------------------------------------------------+
| Gerald W. Lester, President, KNG Consulting LLC |
| Email: Gerald...@kng-consulting.net |
+------------------------------------------------------------------------+
Alexandre Ferrieux
OK, crashes on 8.5 HEAD Linux too.
Please file an SF ticket, will work from there.
(note that there are other opened bugs about traces in the 8.5 branch,
like 3062331, but this one seems a bit different)
-Alex
(gdb) where
#0 0x009a1a29 in SetListFromAny (interp=0x804c218, objPtr=0x804cc58)
at /users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/tclListObj.c:
1744
#1 0x009a03cf in Tcl_ListObjGetElements (interp=0x804c218,
listPtr=0x804cc58, objcPtr=0xbfffe28c, objvPtr=0xbfffe280) at /users/
ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/tclListObj.c:447
#2 0x009c5b61 in Tcl_SetReturnOptions (interp=0x804c218,
options=0x804cc58) at /users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../
generic/tclResult.c:1519
#3 0x0096b79f in TclExecuteByteCode (interp=0x804c218,
codePtr=0x805f680) at /users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../
generic/tclExecute.c:2008
#4 0x009c119a in TclObjInterpProcCore (interp=0x804c218,
procNameObj=0x805dab8, skip=1, errorProc=0x9c16d9 <MakeProcError>) at /
users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/tclProc.c:1760
#5 0x009c10ee in TclObjInterpProc (clientData=0x805faf8,
interp=0x804c218, objc=1, objv=0x804cad8) at /users/ferrieux/src/tcl/
cvs/8.5/tcl/unix/../generic/tclProc.c:1654
#6 0x00915b8a in TclEvalObjvInternal (interp=0x804c218, objc=1,
objv=0x804cad8, command=0x8060f8c "ns::nsConfigGet \n", length=17,
flags=0) at /users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/
tclBasic.c:3700
#7 0x00916cd5 in TclEvalEx (interp=0x804c218, script=0x8060cf8
"set ::errorLevel -1 \nset ::errorStack {} \ntrace add
variable ::errorInfo write { \n\tset __n [ info level ] \n\tif {!
[regexp {\\n invoked from within\\n} $::errorInfo]} { \n\t
\tset ::errorLevel -1; \n\t\tset :"..., numBytes=677, flags=0,
line=30, clNextOuter=0x0, outerScript=0x8060cf8 "set ::errorLevel -1
\nset ::errorStack {} \ntrace add variable ::errorInfo write { \n\tset
__n [ info level ] \n\tif {![regexp {\\n invoked from within\\n}
$::errorInfo]} { \n\t\tset ::errorLevel -1; \n\t\tset :"...) at /users/
ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/tclBasic.c:4397
#8 0x009162fb in Tcl_EvalEx (interp=0x804c218, script=0x8060cf8
"set ::errorLevel -1 \nset ::errorStack {} \ntrace add
variable ::errorInfo write { \n\tset __n [ info level ] \n\tif {!
[regexp {\\n invoked from within\\n} $::errorInfo]} { \n\t
\tset ::errorLevel -1; \n\t\tset :"..., numBytes=677, flags=0) at /
users/ferrieux/src/tcl/cvs/8.5/tcl/unix/../generic/tclBasic.c:4054
#9 0x0099c6fb in Tcl_FSEvalFileEx (interp=0x804c218,
pathPtr=0x805dc20, encodingName=0x0) at /users/ferrieux/src/tcl/cvs/
8.5/tcl/unix/../generic/tclIOUtil.c:1809
#10 0x009a4a34 in Tcl_Main (argc=-1, argv=0xbffff1dc,
appInitProc=0x8048672 <Tcl_AppInit>) at /users/ferrieux/src/tcl/cvs/
8.5/tcl/unix/../generic/tclMain.c:441
#11 0x08048665 in main (argc=2, argv=0xbffff1d4) at /users/ferrieux/
src/tcl/cvs/8.5/tcl/unix/../unix/tclAppInit.c:87
Alexandre Ferrieux
wrote:
>
> OK, crashes on 8.5 HEAD Linux too.
> Please file an SF ticket, will work from there.
> (note that there are other opened bugs about traces in the 8.5 branch,
> like 3062331, but this one seems a bit different)
Never mind, I filed this as bug 3138178:
https://sourceforge.net/tracker/?func=detail&aid=3138178&group_id=10894&atid=110894
Miguel instantly found the associated fix in 8.6, and drove my hand
for the backport, which is attached there.
Will commit as soon as we stop one test (stack-3.1) from failing on
it. Stay tuned.
-Alex
Harald Oehlmann
wrote:
> for the backport, which is attached there.
> Will commit as soon as we stop one test (stack-3.1) from failing on
> it. Stay tuned.
>
> -Alex
Thank you all!
Maybee you may write more about the circumstances when the crash
happens.
Harald
Alexandre Ferrieux
Oh that's simply "any write trace on ::errorInfo". As it turns out,
the bytecode execution engine heavily caches things, and
since ::errorInfo is touched whenever an error status is returned,
this cacheing plays badly with a trace on the variable. That didn't
occur in older versions of Tcl because the cacheing was less
aggressive. The patch disables it around all the error-setting calls,
exactly as does the equivalent evolution in the 8.6 branch.
-Alex
Harald Oehlmann
wrote:
> > Maybee you may write more about the circumstances when the crash
> > happens.
>
> Oh that's simply "any write trace on ::errorInfo". As it turns out,
> the bytecode execution engine heavily caches things, and
> since ::errorInfo is touched whenever an error status is returned,
> this cacheing plays badly with a trace on the variable. That didn't
> occur in older versions of Tcl because the cacheing was less
> aggressive. The patch disables it around all the error-setting calls,
> exactly as does the equivalent evolution in the 8.6 branch.
>
> -Alex
This sounds more like a workaround than a solution but this is my
outside view.
Thank you,
Harald
Alexandre Ferrieux
Sorry, why a workaround ? Cacheing means quicker access, but at some
points a slower resync is needed. What the patch does is recognize
that all error-setting functions are in that category, and forces a
resync on them. Far from being a workaround, it is the only sane way
of doing things, short of removing the cache entirely (which would
slow down all of bytecode execution -- are you advocating *that* ?).
If you know of a better approach, please submit it as a patch against
the 8.6 branch (which works that way too). If it is greenlighted, I'll
be happy to backport it to 8.5.
-Alex
miguel sofer
>> This sounds more like a workaround than a solution but this is my
>> outside view.
>
> Sorry, why a workaround ? Cacheing means quicker access, but at some
> points a slower resync is needed. What the patch does is recognize
> that all error-setting functions are in that category, and forces a
> resync on them. Far from being a workaround, it is the only sane way
> of doing things, short of removing the cache entirely (which would
> slow down all of bytecode execution -- are you advocating *that* ?).
> If you know of a better approach, please submit it as a patch against
> the 8.6 branch (which works that way too). If it is greenlighted, I'll
> be happy to backport it to 8.5.
Not a workaround, agreed with Alex. This is the way things are designed
in the bytecode engine, the bug was an "oversight".
To be precise, the "thing" that is cached by the bytecode engine (tebc)
is a pointer to the execution stack's top. During execution, this
pointer is stored in a local var (possibly a register, if the compiler
decides so) and updated frequently.
When tebc calls out to anything that may run bytecodes (ie, anything
that is able to do an eval), it needs to DECACHE that pointer -
communicate the current state to the rest of the system (by setting a
field in a global struct) so that it knows where to start using the
stack. If it doesn't, currently live memory will be overwritten by the
new eval.
The bug was that the current state was not decached before calling
error-setting functions, but those can do evals via traces on the global
vars. Boom.
This fixes the bug.
Harald Oehlmann
> The bug was that the current state was not decached before calling
> error-setting functions, but those can do evals via traces on the global
> vars. Boom.
>
> This fixes the bug.
Thank you, Alex and Miguel, for the explanations and your (often
magic) work on TCL.
Sorry calling the fix "workaround", no (better) idea here, no patch,
green light.
Harald