[Texmacs-dev] address@hidden: Debugging memory management in TeXmacs]

[Joris van der Hoeven]

----- Forwarded message from Lionel Elie Mamane <address@hidden> -----

X-Original-To: address@hidden
From: Lionel Elie Mamane <address@hidden>
To: address@hidden, address@hidden
Subject: Debugging memory management in TeXmacs
X-Operating-System: GNU/Linux
X-Request-PGP: http://www.mamane.lu/openpgp/rsa_v4_4096.asc
X-Virus-Scanned: by amavisd-new-20030616-p10 at math.u-psud.fr

Bonjour,

La ML address@hidden a l'air d'être dans les choux, alors je
retombe sur mail privé pour l'instant.


Une idée sur les messages ci-joints?


-- 
Lionel

From: Lionel Elie Mamane <address@hidden>
To: address@hidden
Subject: Debugging memory management in TeXmacs
X-Operating-System: GNU/Linux
X-Request-PGP: http://www.mamane.lu/openpgp/rsa_v4_4096.asc

Hi,

If found a reproducible way to crash TeXmacs, but the test case is
_not_ small, and I have been unable to make it shorter. If someone
intimate with TeXmacs (Joris, Henri?) could help me debug this, I'd be
grateful. The crash happens when using my in-development Coq
integration for TeXmacs, but I don't think it probably my scheme code
is be the culprit: The error is that TeXmacs call free() on a pointer
that was not returned by malloc(), and it seems it happens at a point
where my (Scheme) code is not running. If you have any idea how an
error in my scheme code could trigger this error, I'm listening.

The error happens on both the Debian package and a fresh (Thursday 19
October) self-compiled CVS checkout. I wasn't able to get a meaningful
backtrace.

I see two ways we can work on that:

 - You help me in getting a meaningful backtrace, I do the running the
   program, etc and we communicate by email.

 - I give you an account on my machine, a file that exhibits the
   problem, and you look at it by running TeXmacs remotely on my
   machine through a SSH connection.


What I did to try to get a meaningful backtrace was:

 make clean
 ./configure --enable-debug CXXFLAGS='-O0 -ggdb'
 make
 make install

but nope. The backtrace is completely unusable. Maybe this means the
problem happens in Guile code rather than TeXmacs code? I have to
recompile Guile in debugging mode then?


Thanks in advance for any help,

-- 
Lionel

From: Lionel Elie Mamane <address@hidden>
To: address@hidden
Subject: Re: Debugging memory management in TeXmacs
X-Operating-System: GNU/Linux
X-Request-PGP: http://www.mamane.lu/openpgp/rsa_v4_4096.asc

On Fri, Oct 20, 2006 at 09:56:09AM +0200, Lionel Elie Mamane wrote:

> If found a reproducible way to crash TeXmacs, (...) The error is
> that TeXmacs call free() on a pointer that was not returned by
> malloc() (...) I wasn't able to get a meaningful backtrace.

> The backtrace is completely unusable. Maybe this means the problem
> happens in Guile code rather than TeXmacs code? I have to recompile
> Guile in debugging mode then?

I did that, and indeed I get a real backtrace now. Here's the
beginning of it:

#0  0x00002ac21c15a07b in raise () from /lib/libc.so.6
#1  0x00002ac21c15b84e in abort () from /lib/libc.so.6
#2  0x00002ac21c190639 in __fsetlocking () from /lib/libc.so.6
#3  0x00002ac21c1971a3 in mallopt () from /lib/libc.so.6
#4  0x00002ac21c19722e in free () from /lib/libc.so.6
#5  0x000000000041935f in operator delete (ptr=0x1261bc8) at 
./Classes/Abstract/basic.cpp:46
#6  0x0000000000411304 in ~abstract_struct (this=0x1261bd0) at 
Classes/Abstract/basic.hpp:115
#7  0x000000000040b88a in ~observer (this=0x7fff8faf9f40) at 
Classes/Abstract/observer.hpp:69
#8  0x0000000000605a52 in list_observer (address@hidden, address@hidden) at 
./Classes/Atomic/list_observer.cpp:183
#9  0x0000000000605a9f in insert_observer (address@hidden, address@hidden) at 
./Classes/Atomic/list_observer.cpp:188
#10 0x00000000006d9079 in tree_pointer_rep::set_tree (this=0x10568c0, 
address@hidden) at ./Classes/Atomic/tree_pointer.cpp:69
#11 0x00000000006d90c3 in tree_pointer_rep::notify_detach (this=0x10568c0, 
address@hidden, address@hidden, right=false)
    at ./Classes/Atomic/tree_pointer.cpp:150
#12 0x0000000000605ea7 in list_observer_rep::notify_detach (this=0x126ba48, 
address@hidden, address@hidden, right=false)
    at ./Classes/Atomic/list_observer.cpp:124
#13 0x0000000000628d21 in detach (address@hidden, address@hidden, right=false) 
at ./Classes/Abstract/observer.cpp:103
#14 0x0000000000628dba in detach (address@hidden, address@hidden, right=false) 
at ./Classes/Abstract/observer.cpp:109
#15 0x0000000000628dba in detach (address@hidden, address@hidden, right=false) 
at ./Classes/Abstract/observer.cpp:109
#16 0x000000000062909f in assign (address@hidden, address@hidden) at 
./Classes/Abstract/observer.cpp:123
#17 0x00000000004f61e8 in edit_modify_rep::assign (this=0x9a4340, 
address@hidden, address@hidden)
    at ./Edit/Modify/edit_modify.cpp:70
#18 0x00000000005166b5 in edit_process_rep::start_output (this=0x9a4380) at 
./Edit/Process/edit_session.cpp:268
#19 0x0000000000518a8d in edit_process_rep::process_input (this=0x9a4380) at 
./Edit/Process/edit_session.cpp:228
#20 0x00000000005a7c25 in tmg_process_input () at 
Guile/Glue/glue_editor.cpp:2302
#21 0x00002ac21b4243ee in scm_deval (x=0x2ac21c8c4da0, env=0x2ac21c8ddd10) at 
eval.c:2732
#22 0x00002ac21b4270f3 in scm_dapply (proc=0x2ac21c855010, arg1=0x2974, 
args=0x2ac21c8930c0) at eval.c:3655
#23 0x00002ac21b41c9ba in scm_apply (proc=0x2ac21c854f80, arg1=0x2974, 
args=0x2974) at eval.c:3453
#24 0x00002ac21b41c706 in scm_call_0 (proc=0x2ac21c854f80) at eval.c:3309
#25 0x000000000056d369 in TeXmacs_call (args=0x7fff8fafb6e0) at 
./Guile/Scheme/evaluate.cpp:152
#26 0x00002ac21b473888 in scm_internal_lazy_catch (tag=0x2374, body=0x56d31c 
<TeXmacs_call>, body_data=0x7fff8fafb6e0,
    handler=0x56d574 <TeXmacs_lazy_catcher(void*, scm_unused_struct*, 
scm_unused_struct*)>, handler_data=0x7fff8fafb6e0) at throw.c:281
#27 0x000000000056d299 in TeXmacs_lazy_call_scm (args=0x7fff8fafb6e0) at 
./Guile/Scheme/evaluate.cpp:172
#28 0x00002ac21b473673 in scm_internal_catch (tag=0x2374, body=0x56d26e 
<TeXmacs_lazy_call_scm>, body_data=0x7fff8fafb6e0,
    handler=0x56d2f8 <TeXmacs_catcher(void*, scm_unused_struct*, 
scm_unused_struct*)>, handler_data=0x7fff8fafb6e0) at throw.c:205
#29 0x000000000056cf93 in TeXmacs_call_scm (args=0x7fff8fafb6e0) at 
./Guile/Scheme/evaluate.cpp:179



Any clue?

-- 
Lionel

From: Lionel Elie Mamane <address@hidden>
To: address@hidden
Subject: Re: Debugging memory management in TeXmacs
X-Operating-System: GNU/Linux
X-Request-PGP: http://www.mamane.lu/openpgp/rsa_v4_4096.asc

On Fri, Oct 20, 2006 at 11:12:05AM +0200, Lionel Elie Mamane wrote:
> On Fri, Oct 20, 2006 at 09:56:09AM +0200, Lionel Elie Mamane wrote:

>> If found a reproducible way to crash TeXmacs, (...) The error is
>> that TeXmacs call free() on a pointer that was not returned by
>> malloc() (...) I wasn't able to get a meaningful backtrace.

>> I have to recompile Guile in debugging mode then?

> I did that, and indeed I get a real backtrace now. Here's the
> beginning of it:

> #4  0x00002ac21c19722e in free () from /lib/libc.so.6
> #5  0x000000000041935f in operator delete (ptr=0x1261bc8) at 
> ./Classes/Abstract/basic.cpp:46
> #6  0x0000000000411304 in ~abstract_struct (this=0x1261bd0) at 
> Classes/Abstract/basic.hpp:115
> #7  0x000000000040b88a in ~observer (this=0x7fff8faf9f40) at 
> Classes/Abstract/observer.hpp:69
> #8  0x0000000000605a52 in list_observer (address@hidden, address@hidden) at 
> ./Classes/Atomic/list_observer.cpp:183
> #9  0x0000000000605a9f in insert_observer (address@hidden, address@hidden) at 
> ./Classes/Atomic/list_observer.cpp:188
> #10 0x00000000006d9079 in tree_pointer_rep::set_tree (this=0x10568c0, 
> address@hidden) at ./Classes/Atomic/tree_pointer.cpp:69

I did some investigation at this point and here are my findings:

(gdb) print t
$3 = (tree &) @0x7fff8fafa050: {rep = 0x1271bd0, static init = UNINIT}
(gdb) print t.rep
$4 = (tree_rep *) 0x1271bd0
(gdb) print this->ptr
$11 = (tree_rep *) 0x1271bd0


So "this" and the argument to set_tree have the same tree_rep
pointer (whatever that is; maybe "tree representation"?). Is this
normal and supported?

-- 
Lionel

From: Lionel Elie Mamane <address@hidden>
To: address@hidden
Subject: Re: Debugging memory management in TeXmacs
X-Operating-System: GNU/Linux
X-Request-PGP: http://www.mamane.lu/openpgp/rsa_v4_4096.asc

On Fri, Oct 20, 2006 at 11:45:27AM +0200, Lionel Elie Mamane wrote:
> On Fri, Oct 20, 2006 at 11:12:05AM +0200, Lionel Elie Mamane wrote:
>> On Fri, Oct 20, 2006 at 09:56:09AM +0200, Lionel Elie Mamane wrote:

>>> If found a reproducible way to crash TeXmacs, (...) The error is
>>> that TeXmacs call free() on a pointer that was not returned by
>>> malloc() (...) I wasn't able to get a meaningful backtrace.

>> #4  0x00002ac21c19722e in free () from /lib/libc.so.6
>> #5  0x000000000041935f in operator delete (ptr=0x1261bc8) at 
>> ./Classes/Abstract/basic.cpp:46
>> #10 0x00000000006d9079 in tree_pointer_rep::set_tree (this=0x10568c0, 
>> address@hidden) at ./Classes/Atomic/tree_pointer.cpp:69

> I did some investigation at this point and here are my findings:

> (gdb) print t
> $3 = (tree &) @0x7fff8fafa050: {rep = 0x1271bd0, static init = UNINIT}
> (gdb) print t.rep
> $4 = (tree_rep *) 0x1271bd0
> (gdb) print this->ptr
> $11 = (tree_rep *) 0x1271bd0

More findings:

At frame:

#12 0x0000000000605ea7 in list_observer_rep::notify_detach (this=0x126ba48, 
address@hidden, address@hidden, right=false)
    at ./Classes/Atomic/list_observer.cpp:124

that is this line:

  if (!nil (o2)) o2->notify_detach (ref, closest, right);


I have (at time of crash):

(gdb) print o2
$35 = {rep = 0x0}
(gdb) print nil(o2)
$39 = true

so it must have been non-null, but something in the o2->notify_detach
call set it to null.

I added a few debug printfs and what I see (on another run, thus
memory addresses not comparable):

Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer pointer>
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer null>
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x1232230, &o2=0x1232238
In list_observer_rep::notify_detach, after o2->notify_detach with 
&o1=0x1232230, &o2=0x1232238
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x11b3358, &o2=0x11b3360
In list_observer_rep::notify_detach, after o2->notify_detach with 
&o1=0x11b3358, &o2=0x11b3360
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer pointer>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x12693f0, &o2=0x12693f8

I also ran TeXmacs under Valgrind:

Assign output (document (concat (unfolded (, document (subgoal 1 is:,   ,   l' 
: list A,   ============================,    rev l' = rev l' ++ nil)), , ))) := 
output (document ())
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, -5 ]>, 
o2=<observer null>, this=0x772c860, &ref=0x8337bf0, &closest=0x7feffd710, 
refdocument (concat (unfolded (, document (subgoal 1 is:,   ,   l' : list A,   
============================,    rev l' = rev l' ++ nil)), , )), closest=output 
(document ())
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, -5 ]>, o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x772c870, &o2=0x772c878
In list_observer_rep::notify_detach, after o2->notify_detach with 
&o1=0x772c870, &o2=0x772c878
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer pointer>, this=0x776e340, &ref=0x777b8d8, &closest=0x7feffd5d0, 
refunfolded (, document (subgoal 1 is:,   ,   l' : list A,   
============================,    rev l' = rev l' ++ nil)), closest=output 
(document ())
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer null>, this=0x7748388, &ref=0x777b8d8, &closest=0x7feffd520, 
refunfolded (, document (subgoal 1 is:,   ,   l' : list A,   
============================,    rev l' = rev l' ++ nil)), closest=output 
(document ())
Entering list_observer_rep::notify_detach, with o1=<observer [ 0, 0, 0, -5 ]>, 
o2=<observer null>, this=0x7777080, &ref=0x777b8d8, &closest=0x7feffd430, 
refunfolded (, document (subgoal 1 is:,   ,   l' : list A,   
============================,    rev l' = rev l' ++ nil)), closest=output 
(document ())
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x7777090, &o2=0x7777098
In list_observer_rep::notify_detach, after o2->notify_detach with 
&o1=0x7777090, &o2=0x7777098
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer null>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x7748398, &o2=0x77483a0
In list_observer_rep::notify_detach, after o2->notify_detach with 
&o1=0x7748398, &o2=0x77483a0
In list_observer_rep::notify_detach, after o1->notify_detach with o1=<observer 
[ 0, 0, 0, -5 ]>, o2=<observer pointer>
In list_observer_rep::notify_detach, after o1->notify_detach with 
&o1=0x776e350, &o2=0x776e358
In tree_pointer_rep::notify_detach, after right, this=0x74bf0f0
==28174==
==28174== Invalid free() / delete / delete[]
==28174==    at 0x4A1B46D: free (vg_replace_malloc.c:233)
==28174==    by 0x41947E: operator delete(void*) (basic.cpp:46)
==28174==    by 0x411423: abstract_struct::~abstract_struct() (basic.hpp:115)
==28174==    by 0x40B9A9: observer::~observer() (observer.hpp:69)
==28174==    by 0x605B71: list_observer(observer, observer) 
(list_observer.cpp:189)
==28174==    by 0x605BBE: insert_observer(observer&, observer) 
(list_observer.cpp:194)
==28174==    by 0x6D94CC: tree_pointer_rep::set_tree(tree) (tree_pointer.cpp:69)
==28174==    by 0x6D97E4: tree_pointer_rep::notify_detach(tree&, tree, bool) 
(tree_pointer.cpp:151)
==28174==    by 0x606746: list_observer_rep::notify_detach(tree&, tree, bool) 
(list_observer.cpp:129)
==28174==    by 0x6290EC: detach(tree&, tree, bool) (observer.cpp:103)
==28174==    by 0x629185: detach(tree&, tree, bool) (observer.cpp:109)
==28174==    by 0x629185: detach(tree&, tree, bool) (observer.cpp:109)
==28174==  Address 0x7720560 is 21,664 bytes inside a block of size 65,536 
alloc'd
==28174==    at 0x4A1B858: malloc (vg_replace_malloc.c:149)
==28174==    by 0x56DB7E: safe_malloc(unsigned long) (fast_alloc.cpp:35)
==28174==    by 0x56DBCC: enlarge_malloc(unsigned long) (fast_alloc.cpp:46)
==28174==    by 0x4194E5: operator new[](unsigned long) (basic.cpp:58)
==28174==    by 0x40C238: array_rep<tree>::array_rep(int) (array.cpp:32)
==28174==    by 0x40C2C3: array<tree>::array(int) (array.hpp:41)
==28174==    by 0x40C2F2: tree::tree(tree_label, int) (tree.hpp:155)
==28174==    by 0x5837E2: scheme_tree_to_tree(tree, hashmap<string, int>, bool) 
(from_scheme.cpp:145)
==28174==    by 0x583833: scheme_tree_to_tree(tree, hashmap<string, int>, bool) 
(from_scheme.cpp:147)
==28174==    by 0x583833: scheme_tree_to_tree(tree, hashmap<string, int>, bool) 
(from_scheme.cpp:147)
==28174==    by 0x583833: scheme_tree_to_tree(tree, hashmap<string, int>, bool) 
(from_scheme.cpp:147)
==28174==    by 0x583833: scheme_tree_to_tree(tree, hashmap<string, int>, bool) 
(from_scheme.cpp:147)

(it complains about many "Use of uninitialised value of size 8",
"Conditional jump or move depends on uninitialised value", but these
seem to come from the Scheme machinery.


Also in the backtrace, the first meaningful thing is:

#17 0x00000000004f61e8 in edit_modify_rep::assign (this=0x9a4340, 
address@hidden, address@hidden)
    at ./Edit/Modify/edit_modify.cpp:70
#18 0x00000000005166b5 in edit_process_rep::start_output (this=0x9a4380) at 
./Edit/Process/edit_session.cpp:268
#19 0x0000000000518a8d in edit_process_rep::process_input (this=0x9a4380) at 
./Edit/Process/edit_session.cpp:228
#20 0x00000000005a7c25 in tmg_process_input () at 
Guile/Glue/glue_editor.cpp:2302



So it is a call to "process-input", most probably from "kbd-return" in
session-edit.scm that is the root of all this.


-- 
Lionel


----- End forwarded message -----