Backport #3532: Segfault/infinite loop/GC bug when a thread aborts on an exception whose to_s method uses a block

• Status: Closed
• Assignee: -

[Paul (Paul Donohue)]

=begin
The attached crash.rb file reliably causes Ruby 1.8.7 to either segfault, get stuck in an infinite loop, or die with a GC bug message. The exact behavior seems to depend on how ruby was compiled.
=end

[Paul (Paul Donohue)]

=begin
Sample output:

ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]
Compiled using "autoconf ; ./configure ; make" with no additional options:
$ ./ruby ~/Work/Projects/crash.rb
/home/psd/Work/Projects/crash.rb:14/home/psd/Work/Projects/crash.rb:4: [BUG] rb_gc_mark(): unknown data type 0x0(0x7fa5bf783e7c) non object
ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]

Aborted
$

ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]
Installed via the Ubuntu 'ruby1.8' package does not appear to have a problem, however downloading the source and patches used to generate the package, and manually compiling them using "autoconf ; ./configure ; make" with no additional options does crash:
$ ./ruby ~/Work/Projects/crash.rb
/home/psd/Work/Projects/crash.rb:14/home/psd/Work/Projects/crash.rb:4: [BUG] Segmentation fault
ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]

Aborted
$

ruby 1.8.7 (2010-04-19 patchlevel 253) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2010.02
Compiled using "autoconf ; ./configure ; make" with no additional options:
$ ./ruby ~/Work/Projects/crash.rb_
/home/psd/Work/Projects/crash.rb:14 ----------------- Register state dump ----------------------
rax = 0x00000000007a76e0 rbx = 0x00000000007a7628 rcx = 0x00000000007a76d0 rdx = 0x00000000000013b9
rdi = 0x0000000000000000 rsi = 0x0000000000000000 rbp = 0x00000000007a7480 rsp = 0x0000000044e71b80
r8 = 0x0000000000000001 r9 = 0x000000004440ce68 r10 = 0x00000000007a76d0 r11 = 0x0000000000000080
r12 = 0x0000000000000018 r13 = 0x0000000000000000 r14 = 0x0000000000000000 r15 = 0x0000000000000000
rip = 0x0000000000411326 rflags = 0x0000000000010246 cs = 0x0000000000000033 fs = 0x00000000007a7628
gs = 0x00000000440c2af0
/home/psd/Work/Projects/crash.rb:4: [BUG] Segmentation fault
ruby 1.8.7 (2010-04-19 patchlevel 253) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2010.02

Aborted
$

ruby 1.8.7 (2010-04-19 patchlevel 253) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2010.02
Installed via ruby-enterprise_1.8.7-2010.02_amd64_ubuntu10.04.deb:
$ ./ruby ~/Work/Projects/crash.rb
/home/psd/Work/Projects/crash.rb:14
(Process is stuck and is running at 100% CPU, 'kill -TERM' will not kill the process, a 'kill -9' is required)

ruby 1.9.1p378 (2010-01-10 revision 26273) [x86_64-linux]
Compiled using "autoconf ; ./configure ; make" with no additional options does not appear to be affected:
$ ./ruby ~/Work/Projects/crash.rb
/home/psd/Work/Projects/crash.rb:14:in `block in ': MyError
$
=end

[shyouhei (Shyouhei Urabe)]

=begin
seems this is a real bug of 1.8.7. 1.8.8dev has no problem here.

zsh % gdb --args ~/target/ruby_1_8_7/bin/ruby crash.rb
GNU gdb (GDB) 7.1-ubuntu
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /home/shyouhei/target/ruby_1_8_7/bin/ruby...done.
(gdb) run
Starting program: /home/shyouhei/target/ruby_1_8_7/bin/ruby crash.rb
[Thread debugging using libthread_db enabled]
crash.rb:14
Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7abf566 in scope_dup (scope=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:8432
8432 scope->flags |= SCOPE_DONT_RECYCLE;
(gdb) bt
#0 0x00007ffff7abf566 in scope_dup (scope=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:8432
#1 0x00007ffff7abf969 in blk_copy_prev (block=0x6626f0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:8518
#2 0x00007ffff7ac06fd in proc_alloc (klass=140737353936720, proc=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:8745
#3 0x00007ffff7ac08ee in rb_block_proc () at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:8801
#4 0x00007ffff7aad9c0 in rb_eval (self=140737353920280, n=0x7ffff7fcbb98) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:3769
#5 0x00007ffff7ab6e7e in rb_call0 (klass=140737353920800, recv=140737353920280, id=10929, oid=10929, argc=0, argv=0x0, body=0x7ffff7fcbb98, flags=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6079
#6 0x00007ffff7ab7699 in rb_call (klass=140737353920800, recv=140737353920280, mid=10929, argc=0, argv=0x0, scope=1, self=140737353920280) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6176
#7 0x00007ffff7aac028 in rb_eval (self=140737353920280, n=0x7ffff7fcb800) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:3521
#8 0x00007ffff7aaa339 in rb_eval (self=140737353920280, n=0x7ffff7fcb760) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:3236
#9 0x00007ffff7ab6e7e in rb_call0 (klass=140737353920800, recv=140737353920280, id=3137, oid=3137, argc=0, argv=0x0, body=0x7ffff7fcb760, flags=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6079
#10 0x00007ffff7ab7699 in rb_call (klass=140737353920800, recv=140737353920280, mid=3137, argc=0, argv=0x0, scope=1, self=6) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6176
#11 0x00007ffff7ab7a18 in vafuncall (recv=140737353920280, mid=3137, n=0, ar=0x7fffffffc4e0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6253
#12 0x00007ffff7ab7b30 in rb_funcall (recv=140737353920280, mid=3137, n=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6270
#13 0x00007ffff7a9ce07 in exc_to_str (exc=140737353920280) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/error.c:425
#14 0x00007ffff7ab52b5 in call_cfunc (func=0x7ffff7a9cda0 <exc_to_str>, recv=140737353920280, len=0, argc=0, argv=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5781
#15 0x00007ffff7ab6282 in rb_call0 (klass=140737354040240, recv=140737353920280, id=5049, oid=5049, argc=0, argv=0x0, body=0x7ffff7fe81d0, flags=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5928
#16 0x00007ffff7ab7699 in rb_call (klass=140737354040240, recv=140737353920280, mid=5049, argc=0, argv=0x0, scope=1, self=6) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6176
#17 0x00007ffff7ab7a18 in vafuncall (recv=140737353920280, mid=5049, n=0, ar=0x7fffffffcaf0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6253
#18 0x00007ffff7ab7b30 in rb_funcall (recv=140737353920280, mid=5049, n=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6270
#19 0x00007ffff7aa35a2 in error_print () at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:1277
#20 0x00007ffff7acb434 in rb_thread_start_0 (fn=0x7ffff7acb549 <rb_thread_yield>, arg=0x7ffff7fcafb8, th=0x660820) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:12510
#21 0x00007ffff7acb903 in rb_thread_initialize (thread=140737353920680, args=140737353920440) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:12630
#22 0x00007ffff7ab527d in call_cfunc (func=0x7ffff7acb79b <rb_thread_initialize>, recv=140737353920680, len=-2, argc=0, argv=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5775
#23 0x00007ffff7ab6282 in rb_call0 (klass=140737354036280, recv=140737353920680, id=2961, oid=2961, argc=0, argv=0x0, body=0x7ffff7fe7370, flags=2) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5928
#24 0x00007ffff7ab7699 in rb_call (klass=140737354036280, recv=140737353920680, mid=2961, argc=0, argv=0x0, scope=1, self=6) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6176
#25 0x00007ffff7ab7e30 in rb_funcall2 (recv=140737353920680, mid=2961, argc=0, argv=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6312
#26 0x00007ffff7abcfa2 in rb_obj_call_init (obj=140737353920680, argc=0, argv=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:7825
#27 0x00007ffff7acb72a in rb_thread_s_new (argc=0, argv=0x0, klass=140737354036280) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:12584
#28 0x00007ffff7ab529e in call_cfunc (func=0x7ffff7acb6ad <rb_thread_s_new>, recv=140737354036280, len=-1, argc=0, argv=0x0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5778
#29 0x00007ffff7ab6282 in rb_call0 (klass=140737354036240, recv=140737354036280, id=3361, oid=3361, argc=0, argv=0x0, body=0x7ffff7fe73c0, flags=0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:5928
#30 0x00007ffff7ab7699 in rb_call (klass=140737354036240, recv=140737354036280, mid=3361, argc=0, argv=0x0, scope=0, self=140737354060440) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:6176
#31 0x00007ffff7aabcbf in rb_eval (self=140737354060440, n=0x7ffff7fcb558) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:3506
#32 0x00007ffff7aaa339 in rb_eval (self=140737354060440, n=0x7ffff7fcb238) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:3236
#33 0x00007ffff7aa40a0 in eval_node (self=140737354060440, node=0x7ffff7fcb238) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:1449
#34 0x00007ffff7aa4cc6 in ruby_exec_internal () at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:1654
#35 0x00007ffff7aa4d84 in ruby_exec () at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:1674
#36 0x00007ffff7aa4ddf in ruby_run () at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/eval.c:1684
#37 0x000000000040095b in main (argc=2, argv=0x7fffffffe898, envp=0x7fffffffe8b0) at /home/shyouhei/ruby.devel.svn/branches/ruby_1_8_7/main.c:48
(gdb)

=end

[Paul (Paul Donohue)]

• File stacktrace stacktrace added

=begin
I'm attaching another stack trace generated using the Ruby-EE package in Ubuntu (which gets stuck running at 100% CPU).

It looks like "block = Data_Make_Struct(klass, struct BLOCK, blk_mark, blk_free, data);" in proc_alloc() in eval.c line 8829 is returning a pointer to rb_block->prev ... so when blk_copy_prev() is called to copy rb_block->prev (which is now a copy of rb_block, such that rb_block->prev->prev points to rb_block->prev), it loops making copies of rb_block->prev until it runs out of memory, at which point the garbage collector loops forever checking the rb_block linked list (which is now recursive).

I don't quite understand yet why Data_Make_Struct would return a pointer to the already allocated rb_block->prev data structure ... perhaps rb_block->prev has been erroneously garbage collected and is being re-allocated?
=end

[Paul (Paul Donohue)]

Incase anyone stumbles across this again, I am fairly confident this was related to:
http://timetobleed.com/the-broken-promises-of-mrireeyarv/

However, I have no idea how someone would go about finding the source of the erroneous garbage collection that led to this ... maybe try to print the contents of rb_block->prev before it is garbage collected and re-allocated, then figure out from that where the object was allocated? That doesn't seem like it would be trivial.

[drbrain (Eric Hodel)]

• Description updated (diff)
• Status changed from Open to Closed

Ruby 1.8.7 is no longer accepting bug fixes so I am closing this issue. See: http://www.ruby-lang.org/en/news/2011/10/06/plans-for-1-8-7/

If you can reproduce this on ruby 1.9.3 or trunk please open a new issue.