bug#25267: guile-2.2 crash in GC

bug#25267: guile-2.2 crash in GC

[Linas Vepstas]

Merry Christmas!

Below is a crash observed in guile-2.2, the git version of 21 December
2016  (last commit 0ce8a9a5e01d3a12d83fea85968e1abb602c9298 Author:
Andy Wingo <wingo@pobox.com>
Date:   Sun Dec 18 23:00:07 2016 +0100)

I do not have any simple test-case to reproduce this (yet?) so this is
an FYI bug report.  It was provoked by a stress test, with the goal of
running some 60+ calls to scm_c_catch in 60+ distinct C++ threads.  I
have no idea if this will crash any other version of guile; I have
never done this stress test before.

Here's what GDB says:

Thread 296 "cogserver" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffc0ff9700 (LWP 3680)]
thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
    mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
    at ../../libguile/threads.c:111
111              while ((chain = *(void **)chain))
(gdb) bt
#0  thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
    mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
    at ../../libguile/threads.c:111
#1  0x00007ffff2a80ffb in GC_mark_from (mark_stack_top=0x7fffc0fe7c60,
    mark_stack_top@entry=0x7fffc0fe7ca0,
    mark_stack=mark_stack@entry=0x7fffc0fe7c50,
    mark_stack_limit=mark_stack_limit@entry=0x7fffc0ff7c50) at mark.c:737
#2  0x00007ffff2a8163e in GC_do_local_mark (local_mark_stack=0x7fffc0fe7c50,
    local_top=0x7fffc0fe7ca0) at mark.c:994
#3  0x00007ffff2a81864 in GC_mark_local (
    local_mark_stack=local_mark_stack@entry=0x7fffc0fe7c50, id=id@entry=0)
    at mark.c:1129
#4  0x00007ffff2a819bf in GC_do_parallel_mark () at mark.c:1157
#5  0x00007ffff2a8282d in GC_mark_some (
    cold_gc_frame=0x7fffc0ff7cb0 "\344\207\315\362\377\177") at mark.c:372
#6  0x00007ffff2a782dd in GC_stopped_mark (
    stop_func=0x7ffff2a77d70 <GC_never_stop_func>) at alloc.c:698
#7  0x00007ffff2a78dca in GC_try_to_collect_inner (
    stop_func=0x7ffff2a77d70 <GC_never_stop_func>) at alloc.c:486
#8  0x00007ffff2a79782 in GC_collect_or_expand (
    needed_blocks=needed_blocks@entry=1,
    ignore_off_page=ignore_off_page@entry=0, retry=retry@entry=0)
    at alloc.c:1344
---Type <return> to continue, or q <return> to quit---
#9  0x00007ffff2a79942 in GC_allocobj (gran=gran@entry=2, kind=1)
    at alloc.c:1434
#10 0x00007ffff2a7f0a6 in GC_generic_malloc_inner (lb=lb@entry=32, k=k@entry=1)
    at malloc.c:140
#11 0x00007ffff2a80114 in GC_generic_malloc_many (lb=32, k=1,
    result=0x5555563f7d88) at mallocx.c:439
#12 0x00007ffff7728c34 in scm_inline_gc_alloc (kind=<optimized out>,
    idx=<optimized out>, freelist=<optimized out>)
    at ../../libguile/gc-inline.h:94
#13 scm_inline_gc_malloc (thread=<optimized out>, bytes=<optimized out>)
    at ../../libguile/gc-inline.h:125
#14 scm_inline_gc_malloc_words (words=<optimized out>, thread=<optimized out>)
    at ../../libguile/gc-inline.h:132
#15 scm_inline_words (n_words=<optimized out>, car=<optimized out>,
    thread=<optimized out>) at ../../libguile/gc-inline.h:163
#16 vm_regular_engine (thread=0x0, vp=0x5555566fbd80,
    registers=0x7fffc0ff7c50, resume=1434328064)
    at ../../libguile/vm-engine.c:1622
#17 0x00007ffff772928e in scm_call_n (proc=0x7fffd971dd70,
    argv=argv@entry=0x7fffc0ff80b0, nargs=nargs@entry=4)
    at ../../libguile/vm.c:1250
#18 0x00007ffff76ac224 in scm_call_4 (proc=<optimized out>,
    arg1=arg1@entry=0x555556750fa0, arg2=arg2@entry=0x555556870fa0,
---Type <return> to continue, or q <return> to quit---
    arg3=arg3@entry=0x55555607d890, arg4=arg4@entry=0x52)
    at ../../libguile/eval.c:502
#19 0x00007ffff769dd55 in display_backtrace_body (a=<optimized out>)
    at ../../libguile/backtrace.c:244
#20 0x00007ffff77251da in vm_regular_engine (thread=0x0, vp=0x5555566fbd80,
    registers=0x7fffc0ff7c50, resume=1434328064)
    at ../../libguile/vm-engine.c:760
#21 0x00007ffff772928e in scm_call_n (proc=proc@entry=0x555556870f80,
    argv=argv@entry=0x0, nargs=nargs@entry=0) at ../../libguile/vm.c:1250
#22 0x00007ffff76ac189 in scm_call_0 (proc=proc@entry=0x555556870f80)
    at ../../libguile/eval.c:475
#23 0x00007ffff7718280 in catch (tag=tag@entry=0x404, thunk=0x555556870f80,
    handler=0x555556870f60, pre_unwind_handler=0x4)
    at ../../libguile/throw.c:138
#24 0x00007ffff77185c5 in scm_catch_with_pre_unwind_handler (
    key=key@entry=0x404, thunk=<optimized out>, handler=<optimized out>,
    pre_unwind_handler=<optimized out>) at ../../libguile/throw.c:252
#25 0x00007ffff771877f in scm_c_catch (tag=tag@entry=0x404,
    body=body@entry=0x7ffff769dc30 <display_backtrace_body>,
    body_data=body_data@entry=0x7fffc0ff8480,
    handler=handler@entry=0x7ffff769e050 <error_during_backtrace>,
    handler_data=handler_data@entry=0x555556870fa0,
    pre_unwind_handler=pre_unwind_handler@entry=0x0,
---Type <return> to continue, or q <return> to quit---
    pre_unwind_handler_data=0x0) at ../../libguile/throw.c:375
#26 0x00007ffff771878e in scm_internal_catch (tag=tag@entry=0x404,
    body=body@entry=0x7ffff769dc30 <display_backtrace_body>,
    body_data=body_data@entry=0x7fffc0ff8480,
    handler=handler@entry=0x7ffff769e050 <error_during_backtrace>,
    handler_data=handler_data@entry=0x555556870fa0)
    at ../../libguile/throw.c:384
#27 0x00007ffff769dc25 in scm_display_backtrace_with_highlights (
    stack=<optimized out>, port=port@entry=0x555556870fa0,
    first=first@entry=0x4, depth=depth@entry=0x4,
    highlights=highlights@entry=0x304) at ../../libguile/backtrace.c:282
#28 0x00007ffff4a6228e in opencog::SchemeEval::catch_handler (
    this=0x7ffec00090c0, tag=<optimized out>, throw_args=<optimized out>)
    at /home/linas/src/novamente/src/atomspace-git/opencog/guile/SchemeEval.cc:403
#29 0x00007ffff77251da in vm_regular_engine (thread=0x0, vp=0x5555566fbd80,
    registers=0x7fffc0ff7c50, resume=1434328064)
    at ../../libguile/vm-engine.c:760
#30 0x00007ffff772928e in scm_call_n (proc=proc@entry=0x55555678e040,
    argv=<optimized out>, nargs=5) at ../../libguile/vm.c:1250
#31 0x00007ffff76ac51b in scm_apply_0 (proc=proc@entry=0x55555678e040,
    args=0x304) at ../../libguile/eval.c:588
#32 0x00007ffff77182ee in catch (tag=tag@entry=0x404, thunk=0x55555678e060,
---Type <return> to continue, or q <return> to quit---
    handler=0x55555678e040, pre_unwind_handler=0x55555678e020)
    at ../../libguile/throw.c:135
#33 0x00007ffff77185c5 in scm_catch_with_pre_unwind_handler (
    key=key@entry=0x404, thunk=<optimized out>, handler=<optimized out>,
    pre_unwind_handler=<optimized out>) at ../../libguile/throw.c:252
#34 0x00007ffff771877f in scm_c_catch (tag=tag@entry=0x404,
    body=<optimized out>, body_data=<optimized out>,
    handler=handler@entry=0x7ffff4a623e0
<opencog::SchemeEval::catch_handler_wrapper(void*, scm_unused_struct*,
scm_unused_struct*)>,
    handler_data=handler_data@entry=0x7ffec00090c0,
    pre_unwind_handler=pre_unwind_handler@entry=0x7ffff4a62110
<opencog::SchemeEval::preunwind_handler_wrapper(void*,
scm_unused_struct*, scm_unused_struct*)>,
pre_unwind_handler_data=0x7ffec00090c0) at ../../libguile/throw.c:375
#35 0x00007ffff4a624b2 in opencog::SchemeEval::do_eval (this=0x7ffec00090c0,
    expr="(NumberNode ctr)\n")
    at /home/linas/src/novamente/src/atomspace-git/opencog/guile/SchemeEval.cc:552
#36 0x00007ffff4a625ba in opencog::SchemeEval::c_wrap_eval (p=0x7ffec00090c0)
    at /home/linas/src/novamente/src/atomspace-git/opencog/guile/SchemeEval.cc:484
#37 0x00007ffff76a67da in c_body (d=0x7fffc0ff8cf0)
    at ../../libguile/continuations.c:425
#38 0x00007ffff77251da in vm_regular_engine (thread=0x0, vp=0x5555566fbd80,
---Type <return> to continue, or q <return> to quit---
    registers=0x7fffc0ff7c50, resume=1434328064)
    at ../../libguile/vm-engine.c:760
#39 0x00007ffff772928e in scm_call_n (proc=proc@entry=0x555555c77a00,
    argv=argv@entry=0x0, nargs=nargs@entry=0) at ../../libguile/vm.c:1250
#40 0x00007ffff76ac189 in scm_call_0 (proc=proc@entry=0x555555c77a00)
    at ../../libguile/eval.c:475
#41 0x00007ffff7718280 in catch (tag=tag@entry=0x404, thunk=0x555555c77a00,
    handler=0x555555c779e0, pre_unwind_handler=0x555555c779c0)
    at ../../libguile/throw.c:138
#42 0x00007ffff77185c5 in scm_catch_with_pre_unwind_handler (
    key=key@entry=0x404, thunk=<optimized out>, handler=<optimized out>,
    pre_unwind_handler=<optimized out>) at ../../libguile/throw.c:252
#43 0x00007ffff771877f in scm_c_catch (tag=tag@entry=0x404,
    body=body@entry=0x7ffff76a67d0 <c_body>,
    body_data=body_data@entry=0x7fffc0ff8cf0,
    handler=handler@entry=0x7ffff76a6a60 <c_handler>,
    handler_data=handler_data@entry=0x7fffc0ff8cf0,
    pre_unwind_handler=pre_unwind_handler@entry=0x7ffff76a68c0
<pre_unwind_handler>, pre_unwind_handler_data=0x55555597f040) at
../../libguile/throw.c:375
#44 0x00007ffff76a6dd0 in scm_i_with_continuation_barrier (
    body=body@entry=0x7ffff76a67d0 <c_body>,
    body_data=body_data@entry=0x7fffc0ff8cf0,
    handler=handler@entry=0x7ffff76a6a60 <c_handler>,
---Type <return> to continue, or q <return> to quit---
    handler_data=handler_data@entry=0x7fffc0ff8cf0,
    pre_unwind_handler=pre_unwind_handler@entry=0x7ffff76a68c0
<pre_unwind_handler>, pre_unwind_handler_data=0x55555597f040)
    at ../../libguile/continuations.c:363
#45 0x00007ffff76a6e65 in scm_c_with_continuation_barrier (
    func=<optimized out>, data=<optimized out>)
    at ../../libguile/continuations.c:459
#46 0x00007ffff2a8aa45 in GC_call_with_gc_active (
    fn=fn@entry=0x7ffff7716580 <with_guile_trampoline>,
    client_data=client_data@entry=0x7fffc0ff8dc0) at pthread_support.c:1303
#47 0x00007ffff7716ed1 in with_guile (base=base@entry=0x7fffc0ff8d90,
    data=data@entry=0x7fffc0ff8dc0) at ../../libguile/threads.c:673
#48 0x00007ffff2a84812 in GC_call_with_stack_base (
    fn=fn@entry=0x7ffff7716e40 <with_guile>, arg=arg@entry=0x7fffc0ff8dc0)
    at misc.c:1925
#49 0x00007ffff77171f8 in scm_i_with_guile (dynamic_state=<optimized out>,
    data=data@entry=0x7ffec00090c0,
    func=func@entry=0x7ffff4a625a0 <opencog::SchemeEval::c_wrap_eval(void*)>)
    at ../../libguile/threads.c:688
#50 scm_with_guile (
    func=func@entry=0x7ffff4a625a0 <opencog::SchemeEval::c_wrap_eval(void*)>,
    data=data@entry=0x7ffec00090c0) at ../../libguile/threads.c:694
#51 0x00007ffff4a6257e in opencog::SchemeEval::eval_expr (this=0x7ffec00090c0,
---Type <return> to continue, or q <return> to quit---
    expr=...)
    at /home/linas/src/novamente/src/atomspace-git/opencog/guile/SchemeEval.cc:456
#52 0x00007ffff3d91eff in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#53 0x00007ffff337a464 in start_thread (arg=0x7fffc0ff9700)
    at pthread_create.c:333
#54 0x00007ffff30bd9df in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:105
(gdb)


and info thr shows 373 threads

-- Linas

bug#25267: guile-2.2 crash in GC

[Linas Vepstas]

FYI, this is quickly and easily reproducible, happens within seconds,
and hits the same spot every time. Note-to-self (not for general
consumption): my unit test to provoke this is to start the cogserver
and run this shell script:

#!/bin/bash

i=0
while true ; do
  let i=$i+1
  if [ "$(($i % 2000))" -eq "0" ] ; then
    echo loop $i
  fi
  # echo '(display ctr)' | nc localhost 17001
  echo '(NumberNode ctr)' | nc localhost 17001
done

other testing variants are described in
https://github.com/opencog/opencog/issues/2550

bug#25267: crashes here only for invalid scheme

[Linas Vepstas]

FYI: important note: this crashes only because an exception path is
taken. Due to a "bug" in the shell script above, `ctr` is undefined,
so an unbound-variable exception is thrown.  When the scheme is valid,
then it does NOT crash here!

--linas


opencog> (NumberNode ctr)
Entering scheme shell; use ^D or a single . on a line by itself to exit.
guile> Backtrace:
In ice-9/boot-9.scm:
 157: 12 [catch #t #<catch-closure f83bce0> ...]
In unknown file:
   ?: 11 [apply-smob/1 #<catch-closure f83bce0>]
In ice-9/boot-9.scm:
 157: 10 [catch #t #<catch-closure f83b5c0> ...]
In unknown file:
   ?: 9 [apply-smob/1 #<catch-closure f83b5c0>]
   ?: 8 [call-with-input-string "(NumberNode ctr)\n" ...]
In ice-9/boot-9.scm:
2320: 7 [save-module-excursion #<procedure f818930 at
ice-9/eval-string.scm:65:9 ()>]
In ice-9/eval-string.scm:
  44: 6 [read-and-eval #<input: string f8049c0> #:lang ...]
  37: 5 [lp (NumberNode ctr)]
In ice-9/eval.scm:
 387: 4 [eval # ()]
 393: 3 [eval #<memoized ctr> ()]
In unknown file:
   ?: 2 [memoize-variable-access! #<memoized ctr> #<directory
(guile-user) bb3c60>]
In ice-9/boot-9.scm:
 102: 1 [#<procedure f181e80 at ice-9/boot-9.scm:97:6 (thrown-k .
args)> unbound-variable ...]
In unknown file:
   ?: 0 [apply-smob/1 #<catch-closure f83b580> unbound-variable ...]

ERROR: In procedure apply-smob/1:
ERROR: Unbound variable: ctr
ABORT: unbound-variable

bug#25267: guile-2.2 crash in GC

[Andy Wingo]

On Sat 24 Dec 2016 19:43, Linas Vepstas <linasvepstas@gmail.com> writes:

> Thread 296 "cogserver" received signal SIGSEGV, Segmentation fault.
> [Switching to Thread 0x7fffc0ff9700 (LWP 3680)]
> thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
>     mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
>     at ../../libguile/threads.c:111
> 111              while ((chain = *(void **)chain))
> (gdb) bt
> #0  thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
>     mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
>     at ../../libguile/threads.c:111
> #1  0x00007ffff2a80ffb in GC_mark_from (mark_stack_top=0x7fffc0fe7c60,
>     mark_stack_top@entry=0x7fffc0fe7ca0,
>     mark_stack=mark_stack@entry=0x7fffc0fe7c50,
>     mark_stack_limit=mark_stack_limit@entry=0x7fffc0ff7c50) at mark.c:737

I ran into this one too!  I think I fixed it; can you verify?

Andy

bug#25267: guile-2.2 crash in GC

[Linas Vepstas]

On Mon, Jan 9, 2017 at 3:53 PM, Andy Wingo <wingo@pobox.com> wrote:
> On Sat 24 Dec 2016 19:43, Linas Vepstas <linasvepstas@gmail.com> writes:
>
>> [Switching to Thread 0x7fffc0ff9700 (LWP 3680)]
>> thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
>>     mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
>>     at ../../libguile/threads.c:111
>> 111              while ((chain = *(void **)chain))
>
> I ran into this one too!  I think I fixed it; can you verify?

Yep, this is now fixed. You can close this.

(20 minutes of cpu time racked up on it. git version as of today:
7e93950552cd9e85a1f3eb73faf16e8423b0fbbe )

--linas

bug#25267: guile-2.2 crash in GC

[Andy Wingo]

On Tue 10 Jan 2017 07:45, Linas Vepstas <linasvepstas@gmail.com> writes:

> On Mon, Jan 9, 2017 at 3:53 PM, Andy Wingo <wingo@pobox.com> wrote:
>> On Sat 24 Dec 2016 19:43, Linas Vepstas <linasvepstas@gmail.com> writes:
>>
>>> [Switching to Thread 0x7fffc0ff9700 (LWP 3680)]
>>> thread_mark (addr=0x5555558f7700, mark_stack_ptr=<optimized out>,
>>>     mark_stack_limit=0x7fffc0ff7c50, env=<optimized out>)
>>>     at ../../libguile/threads.c:111
>>> 111              while ((chain = *(void **)chain))
>>
>> I ran into this one too!  I think I fixed it; can you verify?
>
> Yep, this is now fixed. You can close this.
>
> (20 minutes of cpu time racked up on it. git version as of today:
> 7e93950552cd9e85a1f3eb73faf16e8423b0fbbe )

Yay.  I am glad I ran into it myself without having to debug this report
:)

Andy