Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

Segmentation fault/memory corruption in TclpAlloc()

288 views
Skip to first unread message

John Caruso

unread,
Sep 30, 2011, 5:05:51 PM9/30/11
to
I've run into a segmentation fault (seemingly caused by memory corruption)
in TclpAlloc(). I'm configuring Tcl with the following options (and it's
being compiled and run on Redhat Enterprise Linux 4.9 x86_64):

./configure \
--prefix=/usr/local/tcl84 \
--enable-64bit \
--enable-symbols \
--enable-threads

I'm specifically working with Tcl 8.4.19, but I've verified that the crash
occurs with both 8.5.9 and 8.5.10. The crashes look like this in gdb:

---- 8< -------------------------------------------------
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1084729984 (LWP 3783)]
TclpAlloc (reqsize=292) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclThreadAlloc.c:344
344 cachePtr->buckets[bucket].firstPtr = blockPtr->b_next;
(gdb) list
339 while (binfo[bucket].blocksize < size) {
340 ++bucket;
341 }
342 if (cachePtr->buckets[bucket].nfree || GetBlocks(cachePtr, bucket)) {
343 blockPtr = cachePtr->buckets[bucket].firstPtr;
344 cachePtr->buckets[bucket].firstPtr = blockPtr->b_next;
345 --cachePtr->buckets[bucket].nfree;
346 ++cachePtr->buckets[bucket].nget;
347 cachePtr->buckets[bucket].nrequest += reqsize;
348 }
(gdb) backtrace
#0 TclpAlloc (reqsize=292) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclThreadAlloc.c:344
#1 0x0000002a959022d5 in Tcl_Alloc (size=4023649519) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:1002
#2 0x0000002a959185f0 in TclInitByteCodeObj (objPtr=0x20aacb0, envPtr=0x40a6f660)
at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCompile.c:1805
#3 0x0000002a9591a85d in TclSetByteCodeFromAny (interp=0x36d07d0, objPtr=0x20aacb0, hookProc=0, clientData=0x0)
at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCompile.c:427
[...etc...]
---- 8< -------------------------------------------------

The Tcl_Alloc()/TclpAlloc() sequence is always the last thing on the call
stack, though the calling routines may differ. The problem is that blockPtr
(aka cachePtr->buckets[bucket].firstPtr) is an invalid pointer:

---- 8< -------------------------------------------------
(gdb) print bucket
$1 = 4
(gdb) print cachePtr->buckets[bucket]
$2 = {firstPtr = 0x2aef8804ef, nfree = 1, nget = 7429, nput = 4813, nwait = 0, nlock = 133, nrequest = 658018}
(gdb) print blockPtr
$3 = (Block *) 0x2aef8804ef
(gdb) print blockPtr->b
Cannot access memory at address 0x2aef8804ef
---- 8< -------------------------------------------------

One potentially significant fact: over the dozens of crashes I've observed,
the crash *always* happens with bucket 4.

Also: in the backtrace above, notice that the size variable is 4023649519
in the Tcl_Alloc() stack frame (#1) but reqsize is 292 in the TclpAlloc()
stack frame (#0)--despite the fact that Tcl_Alloc() just calls TclpAlloc()
and passes its size value in as reqsize, so the two variables should be
the same. Also, there's no hex address printed before stack frame #0, and
there are local variables in TclpAlloc() that gdb was unable to report
("Variable 'size' is not available"). All of which led me to believe there
might be stack corruption going on that's affecting gdb's ability to debug
the crash.

One of the things I've done to try debugging this issue supports that
guess. To test the possibility that the crashes might be caused by a
free'd pointer being accessed, I recompiled Tcl with the free() calls in
TclpFree() and TclFreeAllocCache() disabled (one in the former and two in
the latter). When I did this the crash still occurred--but now the size
and reqsize variables matched, the hex address was printed correctly for
stack frame #0, the size variable within TclpAlloc() was available, etc:

---- 8< -------------------------------------------------
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1084729984 (LWP 31246)]
0x0000002a9597a397 in TclpAlloc (reqsize=184) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclThreadAlloc.c:344
344 cachePtr->buckets[bucket].firstPtr = blockPtr->b_next;
(gdb) print size
$1 = 201
(gdb) bt
#0 0x0000002a9597a397 in TclpAlloc (reqsize=184) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclThreadAlloc.c:344
#1 0x0000002a95909697 in Tcl_Alloc (size=184) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:1002
#2 0x0000002aa39487fb in CRYPTO_malloc () from /usr/local/openssl-64bit/lib/libcrypto.so.0.9.8
#3 0x0000002aa37c87c3 in ssl_cert_dup () from /usr/local/openssl-64bit/lib/libssl.so.0.9.8
[...]
---- 8< -------------------------------------------------

The fact that removing free() calls has any effect at all would seem to
mean that a freed pointer is in fact being referenced somewhere, but the
fact that the crash still occurs means this isn't the only problem.

If you're wondering how to reproduce this crash: unfortunately, so far I
can only reproduce it as part of a complex series of operations within a
larger suite of software above Tcl. I'd love to be able to boil it down
to a simpler test case, but I'm not sure if I can get to that point (given
the number of puts and gets to the memory buckets I don't know how I could
reproduce the required sequence of allocations and frees).

So: can someone offer any pointers on ways to debug this issue? I've
tried --enable-symbols=mem but it didn't produce useful results thus far
(and given the overall complexity of the software stack I can't meet the
requirement that all parts of the stack call the Tcl debugging routines).
I've also tried valgrind, but haven't had much luck there (I haven't had
a chance to try it again since I've been testing the no-free version of
Tcl--that might make it work better). Any and all assistance would be
greatly appreciated.

I do have more information (though these are the critical points), but
this is already too long, so I'll leave it there. Feel free either to
respond here or email me directly (just remove "SPAM" and "AWAY" from
my email address) if you'd like to help or want more info.

- John

Alexandre Ferrieux

unread,
Oct 1, 2011, 5:02:01 AM10/1/11
to
On Sep 30, 11:05 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
>
> [mem corrupted]
>
> I've also tried valgrind, but haven't had much luck there (I haven't had
> a chance to try it again since I've been testing the no-free version of
> Tcl--that might make it work better).  Any and all assistance would be
> greatly appreciated.

By "no luck", do you mean that valgrind detects nothing, or on the
contrary that it barks all the time, drowning the useful signal ?
Also, what valgrind flags have you tried ?

As a side note, I assume you're lucky enough that the problem occurs
pretty early in terms of CPU consumption by your many-layer app;
otherwise, to reach the interesting point under valgrind (which
emulates the CPU), you'd have to wait for ages. Do you confirm that
you waited long enough to reach that point ?

-Alex

miguel sofer

unread,
Oct 1, 2011, 11:24:49 AM10/1/11
to
The fact that we cannot repro will make this a bit tougher.

You do mention "a complex series of operations within a larger suite
of software above Tcl", so I am aguessing that there is further C/C++
code. You also explicitly enable threads, so maybe it is a threaded
app or extension.

Under those conditions, the usual first suspect is a violation of
Tcl's threading model: an interp can only be addressed from the thread
that created it. Does your app or extension respect this requirement?

Cheers
Miguel

John Caruso

unread,
Oct 1, 2011, 1:06:53 PM10/1/11
to
In article <7e225660-2089-46ea...@t11g2000yqk.googlegroups.com>, miguel sofer wrote:
> Under those conditions, the usual first suspect is a violation of
> Tcl's threading model: an interp can only be addressed from the thread
> that created it. Does your app or extension respect this requirement?

I believe so. It's a Tcl web application running on top of AOLserver
3.5.11 with the nsopenssl, tDOM and nsoracle modules. We've been running
this app on AOLserver 3.4.2 and its bundled Tcl 8.3 interpreter for many
years, and this bug does *not* reproduce with that software stack--it only
begins occurring with AOLserver 3.5.11 and unbundled Tcl (8.4.19, though
as I say I can reproduce it with 8.5.10 as well).

I've also reproduced the bug with AOLserver 4.5.1, so if it's an AOLserver
issue it's not one that's been resolved in later releases either. However,
the fact that it's bombing consistently in TclpAlloc() (with varying
calling routines) would seem to indicate that it's a Tcl problem, and the
fact that disabling free() calls in the Tcl source changed the behavior
seems like it points in that direction as well.

- John

John Caruso

unread,
Oct 1, 2011, 1:19:24 PM10/1/11
to
In article <f08d2c84-4194-4328...@t16g2000yqm.googlegroups.com>, Alexandre Ferrieux wrote:
> On Sep 30, 11:05 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
> wrote:
> By "no luck", do you mean that valgrind detects nothing, or on the
> contrary that it barks all the time, drowning the useful signal ?
> Also, what valgrind flags have you tried ?

Honestly, I barely tried valgrind because a) it gave a constant stream
of messages, drowing useful information that might have been there (though
I saw no errors as I watched the output go by), b) I wasn't sure if I had
the best flags to catch this error anyway, c) the runs on which I used it
and --enable-symbols=mem corresponded (coincidentally, I'm fairly sure) to
a change in the system state that caused the problem to go from dead easy
to reproduce to much harder, d) it's a heavily-threaded web server, so
running it under valgrind is tricky in the first place.

Which flags do you recommend?

> As a side note, I assume you're lucky enough that the problem occurs
> pretty early in terms of CPU consumption by your many-layer app;
> otherwise, to reach the interesting point under valgrind (which
> emulates the CPU), you'd have to wait for ages. Do you confirm that
> you waited long enough to reach that point ?

Nope, I can't confirm that. I set valgrind aside to continue with gdb
testing after a few runs since I wanted to get a better handle on the
bug before trying to set valgrind on it.

- John

Alexandre Ferrieux

unread,
Oct 1, 2011, 1:35:00 PM10/1/11
to
On Oct 1, 7:19 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
> In article <f08d2c84-4194-4328-ab7b-8df0e18c3...@t16g2000yqm.googlegroups.com>, Alexandre Ferrieux wrote:
> > On Sep 30, 11:05 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
> > wrote:
> > By "no luck", do you mean that valgrind detects nothing, or on the
> > contrary that it barks all the time, drowning the useful signal ?
> > Also, what valgrind flags have you tried ?
>
> Honestly, I barely tried valgrind because a) it gave a constant stream
> of messages, drowing useful information that might have been there (though
> I saw no errors as I watched the output go by), b) I wasn't sure if I had
> the best flags to catch this error anyway, c) the runs on which I used it
> and --enable-symbols=mem corresponded (coincidentally, I'm fairly sure) to
> a change in the system state that caused the problem to go from dead easy
> to reproduce to much harder, d) it's a heavily-threaded web server, so
> running it under valgrind is tricky in the first place.
>
> Which flags do you recommend?

Well, for mem corruption errors it should detect everything without
specific flags, but I was afraid you had put too many "suppress" flags
(see valgrind -h). Now I know it is 'too much noise', I'd suggest to
add back suppressions one by one, after verifying that they are false
alarmse.

Also, look at the effect of -DPURIFY vs. not. See http://wiki.tcl.tk/28634
.

> > As a side note, I assume you're lucky enough that the problem occurs
> > pretty early in terms of CPU consumption by your many-layer app;
> > otherwise, to reach the interesting point under valgrind (which
> > emulates the CPU), you'd have to wait for ages. Do you confirm that
> > you waited long enough to reach that point ?
>
> Nope, I can't confirm that.  I set valgrind aside to continue with gdb
> testing after a few runs since I wanted to get a better handle on the
> bug before trying to set valgrind on it.

If I were in your seat, I'd give valgrind a second chance, trying not
to change all parameters simultaneously. Carefully adding suppressions
is a sure-fire, if slow, strategy. Single-stepping through gdb and
removing frees is not ;-)

-Alex

Donal K. Fellows

unread,
Oct 2, 2011, 12:46:44 PM10/2/11
to
On 01/10/2011 18:06, John Caruso wrote:
> However, the fact that it's bombing consistently in TclpAlloc() (with varying
> calling routines) would seem to indicate that it's a Tcl problem, and the
> fact that disabling free() calls in the Tcl source changed the behavior
> seems like it points in that direction as well.

That would certainly point to memory corruption - with a double free()
being a prime candidate - but alas not to the point where it actually
happens. But there are things that can be done fairly easily to try to
hunt things down.

The first is to try recompiling everything using a version of Tcl that
has itself been configured with --enable-symbols=mem as this makes Tcl
write junk (the 'a' character IIRC) all over memory once it frees it,
which makes it far easier to detect an access of memory that is
incorrect. It also means that Tcl will detect a double-free(). Note that
all correct code should continue to work just fine in this mode;
anything it finds is a real problem. The cost is performance, which can
be hit quite hard depending on the details of what you're doing.
(Valgrind will find more problems, but it's harder to use right and it
has an even larger performance impact.)

Other possibilities would be mixing up between free() and ckfree() —
memory allocated with malloc() must be freed with free(), memory from
ckalloc() must go back with ckfree() — which must not be mixed up. (We
use a special thread-aware memory manager that is tuned to work with our
threading model; it's very fast indeed with many threads but breaks when
memory is deallocated by the wrong thread.)

But hunting memory problems can be difficult, especially as sometimes
you are trying to see what is missing rather than what is in the wrong
place. Good luck!

Donal.

John Caruso

unread,
Oct 3, 2011, 2:33:53 PM10/3/11
to
In article <5d7e75ad-7286-4965...@i9g2000yqe.googlegroups.com>, Alexandre Ferrieux wrote:
> Now I know it is 'too much noise', I'd suggest to
> add back suppressions one by one, after verifying that they are false
> alarmse.

I was able to get valgrind to run the server until it stopped (though I
saw no mention of the segmentation fault in the valgrind output, so I'm
not 100% sure it stopped because of this bug. valgrind reported 267803
errors (nearly all of them associated with the Oracle instant client
library). I turned off leak checking and got it down to 37825 errors
(again, the majority of them in the Oracle instant client library).
These were the only mentions of TclpAlloc():

==21554== Address 0x245F4F27 is 12,335 bytes inside a block of size 24,576 alloc'd
==21554== at 0x4A18A06: malloc (vg_replace_malloc.c:149)
==21554== by 0x4E058DE: TclpAlloc (tclThreadAlloc.c:935)
==21554== by 0x4DB12D4: Tcl_Alloc (tclCkalloc.c:1002)
[...]
==21554== Address 0x2E253598 is 56 bytes inside a block of size 24,576 alloc'd
==21554== at 0x4A18A06: malloc (vg_replace_malloc.c:149)
==21554== by 0x4E058DE: TclpAlloc (tclThreadAlloc.c:935)
==21554== by 0x4DB12D4: Tcl_Alloc (tclCkalloc.c:1002)
[...]
==21554== Invalid read of size 8
==21554== at 0x4E05964: TclpAlloc (tclThreadAlloc.c:344)
==21554== by 0x4DB12D4: Tcl_Alloc (tclCkalloc.c:1002)
==21554== by 0x4DC75EF: TclInitByteCodeObj (tclCompile.c:1805)
==21554== by 0x4DC985C: TclSetByteCodeFromAny (tclCompile.c:427)
==21554== by 0x4DFF66F: ProcCompileProc (tclProc.c:1424)
==21554== by 0x4DFFB50: TclObjInterpProc (tclProc.c:1002)
==21554== by 0x4DACC44: TclEvalObjvInternal (tclBasic.c:3219)
==21554== by 0x4DD3DC2: TclExecuteByteCode (tclExecute.c:1582)
==21554== by 0x4DD7D0C: TclCompEvalObj (tclExecute.c:1107)
==21554== by 0x4DAED35: Tcl_EvalObjEx (tclBasic.c:4626)
==21554== by 0x4DBBCF0: Tcl_SwitchObjCmd (tclCmdMZ.c:2961)
==21554== by 0x4DACC44: TclEvalObjvInternal (tclBasic.c:3219)
==21554== Address 0xEFB004EF is not stack'd, malloc'd or (recently) free'd

I'm guessing that last sequence is the crash since it's the only "Invalid
read" error valgrind produced on that run and also the only mention of
line 344 of tclThreadAlloc.c (which I already know is the location of the
crash based on the gdb stack trace). Another run produced this sequence:

==836== Invalid read of size 8
==836== at 0x4E05964: TclpAlloc (tclThreadAlloc.c:344)
==836== by 0x4DB12D4: Tcl_Alloc (tclCkalloc.c:1002)
==836== by 0x13B777FA: CRYPTO_malloc (in libcrypto.so.0.9.8)
==836== by 0x13B9984E: bn_expand2 (in libcrypto.so.0.9.8)
==836== by 0x13B97A2C: BN_div (in libcrypto.so.0.9.8)
==836== by 0x13BA2DE8: BN_MONT_CTX_set (in libcrypto.so.0.9.8)
==836== by 0x13BA2FA1: BN_MONT_CTX_set_locked (in libcrypto.so.0.9.8)
==836== by 0x13BB4BC0: RSA_eay_public_decrypt (in libcrypto.so.0.9.8)
==836== by 0x13BB61B4: RSA_verify (in libcrypto.so.0.9.8)
==836== by 0x13BD53F8: EVP_VerifyFinal (in libcrypto.so.0.9.8)
==836== by 0x13BDF0AC: ASN1_item_verify (in libcrypto.so.0.9.8)
==836== by 0x13BF944D: internal_verify (in libcrypto.so.0.9.8)
==836== Address 0xEFBD04EF is not stack'd, malloc'd or (recently) free'd

This doesn't look like it's telling me anything more than gdb already had
in either case, though. If anyone has a recommendation for a next step
with valgrind let me know.

- John

Alexandre Ferrieux

unread,
Oct 3, 2011, 4:33:45 PM10/3/11
to
On Oct 3, 8:33 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
The difference with gdb is that it often reports earlier. For example,
it may report about the very same line, but thousands of times sooner
than the lethal access. This is most efficient for out-of-bounds
writes, which typically take their time to burst. Which may, of
course, not be the case here :/

Are you positive there is no other, earlier error ?
Also, have you tried with -DPURIFY (which replaces bulk allocs with
per-TclObj ones) ?

-Alex

John Caruso

unread,
Oct 4, 2011, 2:27:00 AM10/4/11
to
In article <37c9ab05-d61f-483d...@k10g2000vbn.googlegroups.com>, Alexandre Ferrieux wrote:
> Are you positive there is no other, earlier error ?

There are actually tens of thousands of errors, and most of those happen
before the "Invalid read" error. But the only ones that mention TclpAlloc()
are the ones I listed.

In reviewing the output again I do see this error appearing shortly
before the "Invalid read" error, though:

==21554== Source and destination overlap in memcpy(0x22318450, 0x22318450, 20)
==21554== at 0x4A1A884: memcpy (mac_replace_strmem.c:394)
==21554== by 0xA46CEE7: _intel_fast_memcpy.A (in libclntsh.so.11.1)
==21554== by 0x9968766: kpufprow (in libclntsh.so.11.1)
==21554== by 0x9965E1F: kpufch0 (in libclntsh.so.11.1)
==21554== by 0x9964542: kpufch (in libclntsh.so.11.1)
==21554== by 0x98FA0CE: OCIStmtFetch (in libclntsh.so.11.1)
==21554== by 0x93756B0: ora_get_row (nsoracle.c:2035)
==21554== by 0x4B3B957: Ns_DbGetRow (dbdrv.c:488)
==21554== by 0x4B3E610: NsTclDbCmd (dbtcl.c:488)
==21554== by 0x4DAB4CA: TclInvokeStringCommand (tclBasic.c:1887)
==21554== by 0x4DACC44: TclEvalObjvInternal (tclBasic.c:3219)
==21554== by 0x4DD3DC2: TclExecuteByteCode (tclExecute.c:1582)

And when I re-run valgrind with the "Conditional jump or move depends
on uninitialised value(s)" and "Use of uninitialised value of size 8"
messages suppressed, this is one of the few error messages left. Given
that the memcpy man page states that "If copying takes place between
objects that overlap, the behavior is undefined," it seems like this
could be a source of the memory corruption.

> Also, have you tried with -DPURIFY (which replaces bulk allocs with
> per-TclObj ones) ?

I did, and it didn't appear to make a difference in the valgrind results.

- John

Alexandre Ferrieux

unread,
Oct 4, 2011, 2:42:10 AM10/4/11
to
On Oct 4, 8:27 am, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
> In article <37c9ab05-d61f-483d-8f92-7ff1bdf76...@k10g2000vbn.googlegroups.com>, Alexandre Ferrieux wrote:
> > Are you positive there is no other, earlier error ?
>
> There are actually tens of thousands of errors, and most of those happen
> before the "Invalid read" error.  But the only ones that mention TclpAlloc()
> are the ones I listed.

Oh, but there is no reason for the offender to have TclpAlloc on the
stack ! Indeed, TclpAlloc is the canary in the mine. The corruption
that it detects may have been done in a very different context.

So, don't filter on TclpAlloc. In fact, you'd better filter on the
nature of errors: if there are tens of thousands of them, I guess you
can classify them and discard the red herrings.

As for the "use / cond move depending on uninitialised values", indeed
sometimes they are false alarms, but please verify them before wiping
them out of the radar.

If you're lost in this quest and the (gzipped) valgrind output fits in
a couple of megs, please send it to me by e-mail (look my address up
in GG).

-Alex

John Caruso

unread,
Oct 4, 2011, 3:50:27 AM10/4/11
to
In article <c738acf2-e1de-4f3c...@k6g2000yql.googlegroups.com>, Alexandre Ferrieux wrote:
> So, don't filter on TclpAlloc. In fact, you'd better filter on the
> nature of errors: if there are tens of thousands of them, I guess you
> can classify them and discard the red herrings.

Yep, that's what I did, with the results I mentioned in my last posting.

> If you're lost in this quest and the (gzipped) valgrind output fits in
> a couple of megs, please send it to me by e-mail (look my address up
> in GG).

Thanks, I may do that.

- John

John Caruso

unread,
Oct 4, 2011, 4:17:14 AM10/4/11
to
In article <j6a4hm$1ui$1...@dont-email.me>, Donal K. Fellows wrote:
> On 01/10/2011 18:06, John Caruso wrote:
> The first is to try recompiling everything using a version of Tcl that
> has itself been configured with --enable-symbols=mem as this makes Tcl
> write junk (the 'a' character IIRC) all over memory once it frees it,
> which makes it far easier to detect an access of memory that is
> incorrect.

The information about the 'a' was extremely useful, since it explains this
output I saw when I used --enable-symbols=mem:

Program received signal SIGABRT, Aborted.
[Switching to Thread 1084729984 (LWP 32377)]
0x0000002a95e9f26d in raise () from /lib64/tls/libc.so.6
(gdb) backtrace
#0 0x0000002a95e9f26d in raise () from /lib64/tls/libc.so.6
#1 0x0000002a95ea0a6e in abort () from /lib64/tls/libc.so.6
#2 0x0000002a95ed4641 in __libc_message () from /lib64/tls/libc.so.6
#3 0x0000002a95eda5ac in _int_free () from /lib64/tls/libc.so.6
#4 0x0000002a95eda846 in free () from /lib64/tls/libc.so.6
#5 0x0000002a95900f72 in TclpFree (cp=0x2aa7810c70 "`\017\201'*") at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclAlloc.c:710
#6 0x0000002a9590a8e1 in Tcl_DbCkfree (ptr=0x2aa7810ca8 'a' <repeats 200 times>..., file=0x2a959980c1 "unknown", line=0)
at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:612
#7 0x0000002a9590aaa7 in Tcl_Free (ptr=0x2aa7810ca8 'a' <repeats 200 times>...)
at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:739

So this would seem to verify that there's a double-free going on, as
I'd concluded based on my testing with neutering the free() calls.

By the way, the error "*** glibc detected *** corrupted double-linked
list: 0x0000002aa7810e10 ***" was generated in the AOLserver server log
on this run (and I see similar errors consistently when reproducing the
crash with --enable-symbols=mem).

- John

Alexandre Ferrieux

unread,
Oct 4, 2011, 5:50:12 AM10/4/11
to
On Oct 4, 10:17 am, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
Oh, so now you have a detection earlier than the crash: excellent !
Now you have pinpointed the 2nd of the double-free, you should now
proceed by going deeper than the #7 stack level, to understand what
kind of thing is being freed. Then, gdb's watchpoints (with the actual
pointer values froim a previous run, if they are reproducible) should
help you identify the 1st free.

-Alex


-Alex

Donal K. Fellows

unread,
Oct 4, 2011, 11:14:32 AM10/4/11
to
On 04/10/2011 10:50, Alexandre Ferrieux wrote:
> Oh, so now you have a detection earlier than the crash: excellent !
> Now you have pinpointed the 2nd of the double-free, you should now
> proceed by going deeper than the #7 stack level, to understand what
> kind of thing is being freed. Then, gdb's watchpoints (with the actual
> pointer values froim a previous run, if they are reproducible) should
> help you identify the 1st free.

You can also use Tcl's [memory] command — which is only present in the
--enable-symbols=mem mode — to arrange for all allocations and frees to
be logged; then you can grep through the log and find the problem that way.

Donal.

John Caruso

unread,
Oct 4, 2011, 4:44:48 PM10/4/11
to
In article <j6f7so$el4$1...@dont-email.me>, Donal K. Fellows wrote:
> You can also use Tcl's [memory] command ? which is only present in the
> --enable-symbols=mem mode ? to arrange for all allocations and frees to
> be logged; then you can grep through the log and find the problem that way.

Thanks, that could be a big help. I was considering going the route of
logging all allocations and frees myself, but it's much better if it's
already there.

Unfortunately the double free itself isn't the whole problem, as shown
by the fact that disabling free() calls alleviated the stack corruption
but didn't stop the crashes. To put it another way: the SEGV occurs
because blockPtr (aka cachePtr->buckets[bucket].firstPtr) is pointing to
invalid memory when it's referenced in TclpAlloc(), but that problem is
apparently *not* a result of the pointer having been freed in the past.
But hopefully tracking down the double free will lead me to the other
issue as well.

I discovered one other important piece of information today: I decided to
try reproducing the crash with 32-bit versions of the exact same software
stack (Tcl 8.4.19 with AOLserver 3.5.11), and I was unable to do so--the
crash only happens with the 64-bit versions. So there may be some code
in the mix that's not 64-bit clean. I'm still following up the lead of
the memcpy between two overlapping pointers that valgrind detected, which
may point to a problem in the nsoracle AOLserver module (which seems like
a much more likely candidate for a bug like this than Tcl itself).

- John

John Caruso

unread,
Oct 5, 2011, 9:18:13 PM10/5/11
to
In article <slrnj8ms22.3vs.j...@news.speakeasy.net>, John Caruso wrote:
> In article <j6f7so$el4$1...@dont-email.me>, Donal K. Fellows wrote:
>> You can also use Tcl's [memory] command ? which is only present in the
>> --enable-symbols=mem mode ? to arrange for all allocations and frees to
>> be logged; then you can grep through the log and find the problem that way.
>
> Thanks, that could be a big help. I was considering going the route of
> logging all allocations and frees myself, but it's much better if it's
> already there.

I finally managed to capture a crash in TclpFree() with alloc_tracing
set to 1:

----- 8< ---------------------------------------------------------------
Program received signal SIGABRT, Aborted.
[Switching to Thread 1084729984 (LWP 24464)]
0x0000002a95e9f26d in raise () from /lib64/tls/libc.so.6
(gdb) bt
#0 0x0000002a95e9f26d in raise () from /lib64/tls/libc.so.6
#1 0x0000002a95ea0a6e in abort () from /lib64/tls/libc.so.6
#2 0x0000002a95ed4641 in __libc_message () from /lib64/tls/libc.so.6
#3 0x0000002a95eda5ac in _int_free () from /lib64/tls/libc.so.6
#4 0x0000002a95eda846 in free () from /lib64/tls/libc.so.6
#5 0x0000002a95900f82 in TclpFree (cp=0x2aae7c8830 "01|.*") at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclAlloc.c:710
#6 0x0000002a9590a8f1 in Tcl_DbCkfree (ptr=0x2aae7c8868 'a' <repeats 56 times>, file=0x2a959980e1 "unknown", line=0)
at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:612
#7 0x0000002a9590aab7 in Tcl_Free (ptr=0x2aae7c8868 'a' <repeats 56 times>) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:739
----- 8< ---------------------------------------------------------------

So the presumably double-freed pointer is 0x2aae7c8868. However, this was
the sequence of allocations and frees for that pointer:

----- 8< ---------------------------------------------------------------
ckalloc 2aae7c8868 104 /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclBasic.c 1783
ckfree 2aae7c8868 104 /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclBasic.c 2781
ckalloc 2aae7c8868 104 /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclBasic.c 1783
ckfree 2aae7c8868 104 /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclBasic.c 2781
ckalloc 2aae7c8868 56 unknown 0
ckfree 2aae7c8868 56 unknown 0
ckalloc 2aae7c8868 28 unknown 0
ckfree 2aae7c8868 28 unknown 0
ckalloc 2aae7c8868 56 unknown 0
ckfree 2aae7c8868 56 unknown 0
----- 8< ---------------------------------------------------------------

Nice and tidy, unfortunately--each ckalloc is followed by a ckfree of
the correct size. I'm suspecting that gdb is reporting the current value
of ptr in stack frames 6 and 7, and since Tcl_DbCkfree() does the
"memset((VOID *) ptr, GUARD_VALUE, (size_t) memp->length)" prior to
calling TclpFree() that's the value that's being displayed...which
would mean that the fact that gdb is showing the 'a' values really
wasn't significant in the first place, so this may not actually be
evidence of a double free.

One other thing: in my testing with the --enable-symbols=mem version
of Tcl I'm often seeing variables with the value 0x6161616161616161
(or values similar to and no doubt derived in some way from that, e.g.
0x6161616100000000 or 0x6161616161616a69), which is presumably a result
of the 'a' character (hex 0x61, decimal 97, octal 0141) having been
copied over these areas in memory. For example:

ptr1 = 0x2ab1eba7e8, ptr2 = 0x6161616161616161
$1 = (Tcl_HashEntry **) 0x6161616100000001
#1 0x0000002a9597d202 in Tcl_AppendToObj (objPtr=0x2aaf956858, bytes=0x6161616100000000, length=-1)

Which just shows (again) that there's memory corruption going on.

- John

Alexandre Ferrieux

unread,
Oct 6, 2011, 2:50:54 AM10/6/11
to
On Oct 6, 3:18 am, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
>
> Which just shows (again) that there's memory corruption going on.


John, have you tried what I suggested ?

Here it is again:

> Now you have pinpointed the 2nd of the double-free, you should now
> proceed by going deeper than the #7 stack level, to understand what
> kind of thing is being freed. Then, gdb's watchpoints (with the actual
> pointer values froim a previous run, if they are reproducible) should
> help you identify the 1st free.

The key here is *not* to change everything simultaneously; especially
don't recompile with different flags. This way the pointer values have
a chance to be reproducible.
You start from a -DPURIFY build (maximizing the chances that an
overwrite spans an allocation boundary, which is rarer when the
default Zippy block allocator is used), get your glibc detection or
crash, identify the offending area, then start over under gdb and:

- break after the last malloc of that area before the crash (use
a conditional breakpoint comparing pointer values)
- there, add a hardware watchpoint on the last valid machine word
of the allocated area and continue

From there, gdb must see the point where that word is overwritten,
which is likely correlated with the subsequent heap metadata´s
corruption.

-Alex

John Caruso

unread,
Oct 6, 2011, 4:00:50 AM10/6/11
to
In article <d520601f-0f2f-4bdc...@e9g2000vby.googlegroups.com>, Alexandre Ferrieux wrote:
>> Now you have pinpointed the 2nd of the double-free, you should now
>> proceed by going deeper than the #7 stack level, to understand what
>> kind of thing is being freed. Then, gdb's watchpoints (with the actual
>> pointer values froim a previous run, if they are reproducible) should
>> help you identify the 1st free.
>
> The key here is *not* to change everything simultaneously; especially
> don't recompile with different flags.

I'm not changing anything at the moment, actually. But the point of my
last posting was that the stack trace I'd posted that showed the 'a'
values was *not* actually evidence of a double free--and the fact that
all the allocations and frees for the pointer in question matched up
in a subsequent run just reinforces that. So I haven't actually
pinpointed the 2nd of the double free. And beyond that...

> This way the pointer values have a chance to be reproducible.

...unfortunately, the pointer values are never the same between runs.
The reproduction for this bug involves automating a user workflow that
hits multiple pages in the web application, and it can take anywhere
from 1-25 times through this workflow (as much as 20 minutes, though
it's usually around 2) for the crash to occur--and of course the series
of allocations and frees differs each time and so the pointer addresses
do as well. The lack of a deterministic reproduction process is one of
the main things that's making the debugging of this problem so difficult.

To make matters worse, there isn't just a single type of crash--the
crashes have occurred in different functions within different packages.
And using --enable-symbols=mem changes things even further (and again
not consistently); when using it I've seen crashes in TclpFree(),
TclpAlloc() and Tcl_DeleteHashEntry(), and even when the same one of
these functions shows up in two different stack traces the pointer
values are different.

That said, the majority of the crashes with an --enable-symbols=mem
build happen in TclpFree() and the majority of the crashes with a
standard build happen in TclpAlloc()...but beyond that there's just
not enough consistency to do any debugging that relies on particular
pointer and/or variable values. And the number of allocations and
frees is always in the hundreds of thousands and usually in the
millions, so single stepping isn't really an option either.

Given that slightly more detailed account of the hell I'm going through
with this bug, I'd appreciate any other suggestions people have for
ways to attack it (the information about the 'a' character and "memory
trace" command in particular have been useful). It might also help if
someone could point me to a document describing the Tcl memory allocation
system (and/or other internals), assuming one exists....

- John

miguel sofer

unread,
Oct 6, 2011, 4:30:58 PM10/6/11
to
On Oct 6, 5:00 am, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
> In article <d520601f-0f2f-4bdc-aa2f-b4365ffa8...@e9g2000vby.googlegroups.com>, Alexandre Ferrieux wrote:
> > The key here is *not* to change everything simultaneously; especially
> > don't recompile with different flags.
>
> > This way the pointer values have a chance to be reproducible.
>
> ...unfortunately, the pointer values are never the same between runs.
> The reproduction for this bug involves automating a user workflow that
> hits multiple pages in the web application, and it can take anywhere
> from 1-25 times through this workflow (as much as 20 minutes, though
> it's usually around 2) for the crash to occur--and of course the series
> of allocations and frees differs each time and so the pointer addresses
> do as well.  The lack of a deterministic reproduction process is one of
> the main things that's making the debugging of this problem so difficult.
>
> To make matters worse, there isn't just a single type of crash--the
> crashes have occurred in different functions within different packages.
> And using --enable-symbols=mem changes things even further (and again
> not consistently); when using it I've seen crashes in TclpFree(),
> TclpAlloc() and Tcl_DeleteHashEntry(), and even when the same one of
> these functions shows up in two different stack traces the pointer
> values are different.

John: of course "the crashes occur in different functions": this is
memory CORRUPTION, the site of the crash has zero info value, it is
typically a victim and not a cause.

So please do follow Alex's instructions so that we can help. Again,
you should:

1. compile Tcl with the PURIFY flag set:
$ CFLAGS=-DPURIFY ./configure --enable-symbols
(NOTE: no memory debugging!! ie, do NOT do --enable-symbols=mem)

2. compile all C extensions and/or main progs that include tclInt.h
(aolserver??) against this particular Tcl

3. reproduce your crash under valgrind

4. post the full valgrind output somewhere for us to try and help

John Caruso

unread,
Oct 6, 2011, 6:31:16 PM10/6/11
to
In article <9d789a44-c00b-4610...@g23g2000vbz.googlegroups.com>, miguel sofer wrote:
> So please do follow Alex's instructions so that we can help.

I've been following Alex's suggestions (and Donal's) and have posted the
results, actually. Where I can't follow Alex's suggestions (e.g. because
the conditions he's referring to don't apply in these crashes) I've
explained why. His latest suggestion is just what I'd have been doing
from the beginning if the pointer values were consistent from run to run,
but unfortunately they're not, so there's no way to set a conditional
gdb breakpoint on that basis.

> Again, you should:
> 1. compile Tcl with the PURIFY flag set:
> $ CFLAGS=-DPURIFY ./configure --enable-symbols
> (NOTE: no memory debugging!! ie, do NOT do --enable-symbols=mem)

Yep, I did this (and I haven't ever mixed --enable-symbols=mem and the
-DPURIFY flag, or --enable-symbols=mem and valgrind in general).

> 2. compile all C extensions and/or main progs that include tclInt.h
> (aolserver??) against this particular Tcl
>
> 3. reproduce your crash under valgrind

And I did this (many times). As I mentioned to Alex, the use of -DPURIFY
didn't appear to make a difference in the valgrind results. I'm still
planning to follow up on the "Source and destination overlap in memcpy"
that valgrind identifies shortly before the "Invalid read of size 8",
which is the most promising lead at the moment.

> 4. post the full valgrind output somewhere for us to try and help

Unfortunately I can't post full valgrind output here--it's way too big.
But I can post the output of a run with the thousands of "Conditional
jump or move depends on uninitialised value(s)" and "Use of
uninitialised value of size 8" messages suppressed (the majority of
which occur within the Oracle Instant Client, as I mentioned).

By the way, I did mail valgrind output (including those two message
categories) to Alex but didn't hear back from him. If you'd like a
copy I can mail it to you at your sf dot net address as well.

- John

John Caruso

unread,
Oct 6, 2011, 7:24:58 PM10/6/11
to
In article <slrnj8q0ei.3t4.j...@news.eternal-september.org>, John Caruso wrote:
> #6 0x0000002a9590a8f1 in Tcl_DbCkfree (ptr=0x2aae7c8868 'a' <repeats 56 times>, file=0x2a959980e1 "unknown", line=0)
> at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:612
> #7 0x0000002a9590aab7 in Tcl_Free (ptr=0x2aae7c8868 'a' <repeats 56 times>) at /home/tclbuild/rpm/BUILD/tcl8.4.19/unix/../generic/tclCkalloc.c:739
> ----- 8< ---------------------------------------------------------------
> [...]
> I'm suspecting that gdb is reporting the current value
> of ptr in stack frames 6 and 7, and since Tcl_DbCkfree() does the
> "memset((VOID *) ptr, GUARD_VALUE, (size_t) memp->length)" prior to
> calling TclpFree() that's the value that's being displayed...which
> would mean that the fact that gdb is showing the 'a' values really
> wasn't significant in the first place, so this may not actually be
> evidence of a double free.

I've verified this--gdb shows the original value for ptr in the backtrace
until the memset is executed, and then it shows the 'a' value. So the
fact that there were 'a' values in this backtrace didn't actually mean a
double free was occurring in this particular instance.

- John

miguel sofer

unread,
Oct 7, 2011, 6:34:26 AM10/7/11
to
On Oct 6, 7:31 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
> Unfortunately I can't post full valgrind output here--it's way too big.
> But I can post the output of a run with the thousands of "Conditional
> jump or move depends on uninitialised value(s)" and "Use of
> uninitialised value of size 8" messages suppressed (the majority of
> which occur within the Oracle Instant Client, as I mentioned).
>
> By the way, I did mail valgrind output (including those two message
> categories) to Alex but didn't hear back from him.  If you'd like a
> copy I can mail it to you at your sf dot net address as well.

Alex already sent me that output per email.

I saw the thousands of errors in the Oracle Instant Client, they look
ominous! Does a valgrind run in your functioning old config also show
them?

The problem is that it is quite hard to know if this is a bug in Tcl,
aolserver, the OIC, or something in their interplay. I see no evidence
that the problem lies in Tcl.

Just to make sure: did you recompile aolserver against the new Tcl
version's headers? As I see no reference to Tcl Stubs in the aolserver
tree, it might be relevant.

John Caruso

unread,
Oct 7, 2011, 3:42:16 PM10/7/11
to
In article <d9143cd2-ad1d-40df...@q17g2000yqn.googlegroups.com>, miguel sofer wrote:
> I saw the thousands of errors in the Oracle Instant Client, they look
> ominous! Does a valgrind run in your functioning old config also show
> them?

I just tried it and yep, it does. In that case many of the "Conditional
jump or move depends on unitialised value(s)" errors show up in Tcl
routines as well, BTW. I'm guessing these and the "Use of uninitialised
value of size 8" valgrind messages are harmless and/or false alarms--
among other things, if they weren't I'd expect to see a crash much sooner,
since there are so many of them.

Speaking of "so many" (and false alarms): valgrind reported a total of
46,807,450 errors for this run of the non-crashing config.

> The problem is that it is quite hard to know if this is a bug in Tcl,
> aolserver, the OIC, or something in their interplay.

Welcome to my nightmare. :-)

> Just to make sure: did you recompile aolserver against the new Tcl
> version's headers?

Yes. These are RPM builds, and I do a matched set for Tcl and AOLserver
for each permutation.

- John

Alexandre Ferrieux

unread,
Oct 8, 2011, 5:54:31 AM10/8/11
to
On Oct 7, 9:42 pm, John Caruso <johnSPAMcarAWAY...@myprivacy.ca>
wrote:
>

> Welcome to my nightmare. :-)

Indeed. At this point I'd try to trim down the crashing case, and also
to remove the randomness of runs (so that cond breakpoints and
watchpoints can be used). I'm sure you've already done your best in
that area; I'm just flailing about to save face :P

-Alex


John Caruso

unread,
Feb 2, 2012, 7:45:17 PM2/2/12
to
In article <slrnj8ulgl.244.j...@news.eternal-september.org>, John Caruso wrote:
> Welcome to my nightmare. :-)

Which has finally ended. For anyone who's interested, the problem was in
the tDOM code (not Tcl) -- there's a memcpy() in there that specifies
sizeof(int*) when it should be using sizeof(int), which worked on a 32-bit
architecture where both of those were 4 but caused problems on a 64-bit
architecture where sizeof(int*) was 8 (so the memcpy was copying twice as
much as it should have). Someone else encountered the same problem:

http://tech.groups.yahoo.com/group/tdom/message/1994

Based on what that person said I tried re-running the server in question
under valgrind yet again (with no suppressions and no error limit), and
valgrind still didn't flag the problem that led to this crash (or any
tDOM functions at all, actually). So I'm not sure what I could have done
differently to track it down.

Thanks to everyone who offered suggestions and assistance--it was much
appreciated.

- John

Koen Danckaert

unread,
Feb 3, 2012, 5:25:07 AM2/3/12
to
On 03/02/12 01:45, John Caruso wrote:
> In article<slrnj8ulgl.244.j...@news.eternal-september.org>, John Caruso wrote:
>> Welcome to my nightmare. :-)
>
> Which has finally ended. For anyone who's interested, the problem was in
> the tDOM code (not Tcl) -- there's a memcpy() in there that specifies
> sizeof(int*) when it should be using sizeof(int), which worked on a 32-bit
> architecture where both of those were 4 but caused problems on a 64-bit
> architecture where sizeof(int*) was 8 (so the memcpy was copying twice as
> much as it should have). Someone else encountered the same problem:
>
> http://tech.groups.yahoo.com/group/tdom/message/1994

I actually reported this twice already, once on the old Yahoo mailing list above, and again on the new tDOM site on Github:

http://github.com/tDOM/tdom/issues/2

But I never got any reaction from the tDOM maintainers. Maybe it helps if you add a comment to the issue tracker...

> Based on what that person said I tried re-running the server in question
> under valgrind yet again (with no suppressions and no error limit), and
> valgrind still didn't flag the problem that led to this crash (or any
> tDOM functions at all, actually). So I'm not sure what I could have done
> differently to track it down.

Strange. Valgrind reported it as follows to me:

==21637== Invalid write of size 1
==21637== at 0x4C26321: memcpy (in /usr/lib64/valgrind/amd64-linux/vgpreload_memcheck.so)
==21637== by 0x9F049B9: fastMergeSort (domxslt.c:2682)
==21637== by 0x9F0465D: fastMergeSort (domxslt.c:2646)
==21637== by 0x9F0465D: fastMergeSort (domxslt.c:2646)
==21637== by 0x9F04AEE: sortNodeSetFastMerge (domxslt.c:2711)
==21637== by 0x9F0714F: doSortActions (domxslt.c:3584)
==21637== by 0x9F08D9D: ExecAction (domxslt.c:4150)
==21637== by 0x9F0C60B: ExecActions (domxslt.c:5250)
==21637== by 0x9F0A02B: ExecAction (domxslt.c:4485)
==21637== by 0x9F0C60B: ExecActions (domxslt.c:5250)
==21637== by 0x9F0CD5C: ApplyTemplate (domxslt.c:5432)
==21637== by 0x9F0CF3F: ApplyTemplates (domxslt.c:5478)
==21637== Address 0xa4998f4 is 12 bytes before a block of size 112 free'd
==21637== at 0x4C243AF: free (in /usr/lib64/valgrind/amd64-linux/vgpreload_memcheck.so)
==21637== by 0x5281EF5: Tcl_DeleteCommandFromToken (in /target/staff/koen/12R1/bin/LNa64bin/libtcl8.6.so)
==21637== by 0x52866A5: Tcl_CreateObjCommand (in /target/staff/koen/12R1/bin/LNa64bin/libtcl8.6.so)
==21637== by 0x9F13E35: tcldom_createNodeObj (tcldom.c:605)
==21637== by 0x9F14859: tcldom_xpointerAddCallback (tcldom.c:878)
==21637== by 0x9EE267F: domXPointerChild (dom.c:4717)
==21637== by 0x9F14C77: tcldom_xpointerSearch (tcldom.c:957)
==21637== by 0x9F2298F: tcldom_NodeObjCmd (tcldom.c:3822)
==21637== by 0x52822A0: TclNRRunCallbacks (in /target/staff/koen/12R1/bin/LNa64bin/libtcl8.6.so)
==21637== by 0x52D5566: (within /target/staff/koen/12R1/bin/LNa64bin/libtcl8.6.so)
==21637== by 0x52822A0: TclNRRunCallbacks (in /target/staff/koen/12R1/bin/LNa64bin/libtcl8.6.so)
==21637== by 0xA174C30: (within /target/staff/koen/12R1/chessdir/tcltk8.6/LNa64/lib/xotcl1.6.1/libxotcl1.6.1.so)

--Koen

John Caruso

unread,
Feb 3, 2012, 9:39:06 PM2/3/12
to
In article <jggcm2$ovj$1...@speranza.aioe.org>, Koen Danckaert wrote:
> I actually reported this twice already, once on the old Yahoo mailing list above, and again on the new tDOM site on Github:
>
> http://github.com/tDOM/tdom/issues/2

And many thanks for doing so. We were on the cusp of finding the bug--
I'd just started looking at the memcpy() statements in fastMergeSort()
based on a developer finally narrowing down the issue to XSLT sorting--
when I happened across your posting and patch.

> But I never got any reaction from the tDOM maintainers. Maybe it helps if you add a comment to the issue tracker...

Done.

>> Based on what that person said I tried re-running the server in question
>> under valgrind yet again (with no suppressions and no error limit), and
>> valgrind still didn't flag the problem that led to this crash (or any
>> tDOM functions at all, actually). So I'm not sure what I could have done
>> differently to track it down.
>
> Strange. Valgrind reported it as follows to me:
>
>==21637== Invalid write of size 1
>==21637== at 0x4C26321: memcpy (in /usr/lib64/valgrind/amd64-linux/vgpreload_memcheck.so)
>==21637== by 0x9F049B9: fastMergeSort (domxslt.c:2682)
>==21637== by 0x9F0465D: fastMergeSort (domxslt.c:2646)
>==21637== by 0x9F0465D: fastMergeSort (domxslt.c:2646)
>==21637== by 0x9F04AEE: sortNodeSetFastMerge (domxslt.c:2711)
>==21637== by 0x9F0714F: doSortActions (domxslt.c:3584)
>[...]

Man, that would have been nice (and thanks for posting it since I was
curious to see what the valgrind detection looked like). I reverified
that 1) fastMergeSort doesn't show up anywhere in the output for my
valgrind runs and 2) the only "Invalid ..." errors are "Invalid read
of size X" from TclpAlloc and the Oracle Instant Client's slaac_int
function, which are presumably a result of this bug.

These are the options I was using:

valgrind --trace-children=yes --time-stamp=yes --error-limit=no \
--log-file=/var/tmp/valgrind/server <...server-invocation...>

We're running tDOM as a module under AOLserver 3.5.11, which is also
linked with nsopenssl and nsoracle (and the Oracle Instant Client) and
of course Tcl. I wonder if the fact that AOLserver is a multi-threaded
server process is somehow throwing valgrind off.

- John

GN

unread,
Feb 4, 2012, 1:05:16 AM2/4/12
to
>
> > But I never got any reaction from the tDOM maintainers. Maybe it helps if you add a comment to the issue tracker...
>

The tdom maintainer are thorough but busy people.
The fix suggested by Koen fixes a clear bug. i have applied it to my
fork on github
https://github.com/gustafn/tdom

>  I wonder if the fact that AOLserver is a multi-threaded
> server process is somehow throwing valgrind off.

valgrind is by its nature platform dependent. At least in the current
version under mac os x, it is not capable to debug aolserver/
naviserver. It is usually better to distill a small script exhibiting
the error and debug under plain tcl.

John Caruso

unread,
Feb 7, 2012, 3:54:23 PM2/7/12
to
In article <9af0bfbf-9ffb-4c3c...@bs8g2000vbb.googlegroups.com>, GN wrote:
> valgrind is by its nature platform dependent. At least in the current
> version under mac os x, it is not capable to debug aolserver/
> naviserver. It is usually better to distill a small script exhibiting
> the error and debug under plain tcl.

Sure, but if I could have done that I wouldn't have needed valgrind :-).
The whole problem was determining what was causing the memory corruption
in the first place.

(I'm debugging AOLserver on Redhat Enterprise Linux 4, BTW, and I do get
*some* results from valgrind for AOLserver and also tDOM functions--but
it just wasn't finding the tDOM error that Koen's valgrind runs reported.)

- John
0 new messages