Backport #8144

test_segv_test(TestRubyOptions) test failure

Added by Vit Ondruch about 2 years ago. Updated about 1 year ago.

[ruby-core:53632]
Status:Open
Priority:Normal
Assignee:Yui NARUSE

Description

=begin
After doing several successful builds [1], next build crashed suddenly with:

test_segv_test(TestRubyOptions) [/builddir/build/BUILD/ruby-2.0.0-p0/test/ruby/test_rubyoptions.rb:513]:
Expected /#'\n-e:3:in `kill'\n\n-- C level backtrace information -------------------------------------------\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x175cc9) [0x519cc9] vm_dump.c:647\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x54aef) [0x3f8aef] error.c:283\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_bug+0x41) [0x3f8f01] error.c:302\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x10700d) [0x4ab00d] signal.c:649\n[0xd84410]\n[0xd84430]\n/lib/libc.so.6(kill+0x16) [0x8dcab6]\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_f_kill+0x66) [0x4abaa6] signal.c:424\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x15ad6f) [0x4fed6f] vm_insnhelper.c:1294\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x15f7d9) [0x5037d9] vm_insnhelper.c:1438\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x170eaf) [0x514eaf] vm_insnhelper.c:1528\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x16365c) [0x50765c] insns.def:1017\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x1691d4) [0x50d1d4] vm.c:1175\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_iseq_eval_main+0x8c) [0x50f11c] vm.c:1423\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x57ccc) [0x3fbccc] eval.c:250\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(ruby_exec_node+0x25) [0x3fd535] eval.c:315\n/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(ruby_run_node+0x31) [0x3feff1] eval.c:307\n/builddir/build/BUILD/ruby-2.0.0-p0/ruby() [0x80486b9] main.c:36\n/lib/libc.so.6(__libc_start_main+0xf3) [0x8c7963]\n/builddir/build/BUILD/ruby-2.0.0-p0/ruby() [0x80486e1] main.c:38\n\n-- Other runtime information -----------------------------------------------\n\n* Loaded script: -e\n\n* Loaded features:\n\n".

In readable form:

test_segv_test(TestRubyOptions) [/builddir/build/BUILD/ruby-2.0.0-p0/test/ruby/test_rubyoptions.rb:513]:
Expected /#<Bogus:/ to match "-e:3: [BUG] Segmentation fault
ruby 2.0.0p0 (2013-02-24) [i386-linux]

-- Control frame information -----------------------------------------------
c:0003 p:---- s:0009 e:000008 CFUNC :kill
c:0002 p:0041 s:0004 E:001ffc EVAL -e:3 [FINISH]
c:0001 p:0000 s:0002 E:001d24 TOP [FINISH]

-e:3:in <main>'
-e:3:in
kill'

-- C level backtrace information -------------------------------------------
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x175cc9) [0x519cc9] vm_dump.c:647
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x54aef) [0x3f8aef] error.c:283
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_bug+0x41) [0x3f8f01] error.c:302
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x10700d) [0x4ab00d] signal.c:649
[0xd84410]
[0xd84430]
/lib/libc.so.6(kill+0x16) [0x8dcab6]
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_f_kill+0x66) [0x4abaa6] signal.c:424
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x15ad6f) [0x4fed6f] vm_insnhelper.c:1294
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x15f7d9) [0x5037d9] vm_insnhelper.c:1438
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x170eaf) [0x514eaf] vm_insnhelper.c:1528
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x16365c) [0x50765c] insns.def:1017
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x1691d4) [0x50d1d4] vm.c:1175
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(rb_iseq_eval_main+0x8c) [0x50f11c] vm.c:1423
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(+0x57ccc) [0x3fbccc] eval.c:250
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(ruby_exec_node+0x25) [0x3fd535] eval.c:315
/builddir/build/BUILD/ruby-2.0.0-p0/libruby.so.2.0.0(ruby_run_node+0x31) [0x3feff1] eval.c:307
/builddir/build/BUILD/ruby-2.0.0-p0/ruby() [0x80486b9] main.c:36
/lib/libc.so.6(__libc_start_main+0xf3) [0x8c7963]
/builddir/build/BUILD/ruby-2.0.0-p0/ruby() [0x80486e1] main.c:38

-- Other runtime information -----------------------------------------------

  • Loaded script: -e

  • Loaded features:

".

[1] https://bugs.ruby-lang.org/issues/7521#note-7
=end


Related issues

Follows Backport200 - Backport #8227: addr2line.c compile error on Solaris since r39887 Closed 04/06/2013

Associated revisions

Revision 39887
Added by Yui NARUSE about 2 years ago

  • addr2line.c (kprintf): added from FreeBSD libstand's printf.
    this is consided as async signal safe function.

  • addr2line.c (rb_dump_backtrace_with_lines): use kfprintf.
    [Bug #8144]

Revision 40253
Added by Tomoyuki Chikanaga almost 2 years ago

merge revision(s) 39866,39887,39921,40161,40170: [Backport #8144] [Backport #8227]

* addr2line.c (rb_dump_backtrace_with_lines): output line at once.

* addr2line.c (kprintf): added from FreeBSD libstand's printf.
  this is consided as async signal safe function.

* addr2line.c (rb_dump_backtrace_with_lines): use kfprintf.
  [Bug #8144] 

* addr2line.c (putce): suppress unused return value warning.

* addr2line.c: quad_t and u_quad_t is not available on Solaris.
  __inline is not available with old compilers on Solaris.
   [Bug #8227]

* addr2line.c: use more generic type:
  * u_char -> unsigned char
  * u_short -> unsigned short
  * u_int -> unsigned int
  * u_long -> unsigned long
  * quad_t -> int64_t
  * u_quad_t -> uint64_t

* addr2line.c (imax): inline is defined by configure.

History

#1 Updated by Yui NARUSE about 2 years ago

I also experienced a similar failure on Linux i686 various distribution.
http://www.rubyist.net/~akr/chkbuild/debian/ruby-trunk/log/20130321T151200Z.diff.html.gz
http://c5632.rubyci.org/~chkbuild/ruby-trunk/log/20130321T030302Z.diff.html.gz
http://u32.rubyci.org/~chkbuild/ruby-trunk/log/20130319T230301Z.diff.html.gz

On this debian squeeze it always happen, but on CentOS 5.8/Ubuntu 10.04 it is at random.

My some inspection it seems because fprintf in rb_dump_backtrace_with_lines.
It is called from signal handler and fprintf is async signal unsafe.
This fprintf seems to break some memory value for example rb_cString.
But I doubt this really caused by this...

Anyway on debian squeeze, following patch fixed this.
Could you try this?

diff --git a/addr2line.c b/addr2line.c
index c0fad49..fc12b97 100644
--- a/addr2line.c
+++ b/addr2line.c
@@ -617,21 +617,25 @@ rb_dump_backtrace_with_lines(int num_traces, void *trace, char **syms)
/
fprintf may not be async-signal safe */
for (i = 0; i < num_traces; i++) {
line_info_t *line = &lines[i];
+ #define BUFLEN 256
+ char buf[BUFLEN];
+ int n;

    if (line->line > 0) {
        if (line->filename) {
            if (line->dirname && line->dirname[0]) {
  • fprintf(stderr, "%s %s/%s:%d\n", syms[i], line->dirname, line->filename, line->l
  • n = snprintf(buf, BUFLEN, "%s %s/%s:%d\n", syms[i], line->dirname, line->filenam } else {
  • fprintf(stderr, "%s %s:%d\n", syms[i], line->filename, line->line);
  • n = snprintf(buf, BUFLEN, "%s %s:%d\n", syms[i], line->filename, line->line); } } else {
  • fprintf(stderr, "%s ???:%d\n", syms[i], line->line);
  • n = snprintf(buf, BUFLEN, "%s ???:%d\n", syms[i], line->line); } } else {
  • fprintf(stderr, "%s\n", syms[i]);
  • n = snprintf(buf, BUFLEN, "%s\n", syms[i]); }
  •   n = write(2, buf, n);
    

    }

    for (i = 0; i < num_traces; i++) {

#2 Updated by Vit Ondruch about 2 years ago

Thank you Yui. I could try it, but I am afraid I don't know how to recognize that it works for sure, due to its random nature :/

#3 Updated by Yui NARUSE about 2 years ago

vo.x (Vit Ondruch) wrote:

Thank you Yui. I could try it, but I am afraid I don't know how to recognize that it works for sure, due to its random nature :/

Try below:

while make TESTS='-vn test_segv_test ruby/test_rubyoptions.rb' test-all;do :;done

#4 Updated by Motohiro KOSAKI about 2 years ago

My some inspection it seems because fprintf in rb_dump_backtrace_with_lines.
It is called from signal handler and fprintf is async signal unsafe.
This fprintf seems to break some memory value for example rb_cString.
But I doubt this really caused by this...

I really doubt it.
rb_dump_backtrace_with_lines() is only called from SEGV handler. but SEGV itself shouldn't be happen.
Moreover, I wonder why kill() in libc makes SEGV, not from ruby code.

#5 Updated by Motohiro KOSAKI about 2 years ago

I really doubt it.
rb_dump_backtrace_with_lines() is only called from SEGV handler. but SEGV itself shouldn't be happen.
Moreover, I wonder why kill() in libc makes SEGV, not from ruby code.

Sorry, I was confusion. It was test_segv_test. so, SEGV is not wrong.

#6 Updated by Vit Ondruch about 2 years ago

naruse (Yui NARUSE) wrote:

Try below:

while make TESTS='-vn test_segv_test ruby/test_rubyoptions.rb' test-all;do :;done

I gave it try, running without the patch for 2 hours and no luck to reproduce the original issue on my local machine, therefore there is no point to try the patch. Sorry :/

#7 Updated by Yui NARUSE about 2 years ago

  • Status changed from Open to Closed
  • % Done changed from 0 to 100

This issue was solved with changeset r39887.
Vit, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.


  • addr2line.c (kprintf): added from FreeBSD libstand's printf.
    this is consided as async signal safe function.

  • addr2line.c (rb_dump_backtrace_with_lines): use kfprintf.
    [Bug #8144]

#8 Updated by Tomoyuki Chikanaga about 2 years ago

  • Project changed from Ruby trunk to Backport200
  • Tracker changed from Bug to Backport
  • Status changed from Closed to Assigned
  • Assignee set to Tomoyuki Chikanaga
  • Priority changed from Normal to High

backport r39887 and r39921.
r40161 should be backported at the same time for #8227.

#9 Updated by Tomoyuki Chikanaga almost 2 years ago

  • Status changed from Assigned to Closed

This issue was solved with changeset r40253.
Vit, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.


merge revision(s) 39866,39887,39921,40161,40170: [Backport #8144] [Backport #8227]

* addr2line.c (rb_dump_backtrace_with_lines): output line at once.

* addr2line.c (kprintf): added from FreeBSD libstand's printf.
  this is consided as async signal safe function.

* addr2line.c (rb_dump_backtrace_with_lines): use kfprintf.
  [Bug #8144] 

* addr2line.c (putce): suppress unused return value warning.

* addr2line.c: quad_t and u_quad_t is not available on Solaris.
  __inline is not available with old compilers on Solaris.
   [Bug #8227]

* addr2line.c: use more generic type:
  * u_char -> unsigned char
  * u_short -> unsigned short
  * u_int -> unsigned int
  * u_long -> unsigned long
  * quad_t -> int64_t
  * u_quad_t -> uint64_t

* addr2line.c (imax): inline is defined by configure.

#10 Updated by Vit Ondruch about 1 year ago

  • Status changed from Closed to Open
  • Assignee changed from Tomoyuki Chikanaga to Yui NARUSE
  • Priority changed from High to Normal
  • % Done changed from 100 to 0

=begin
Unfortunately, I met this issue today again, so the applied medicine was not enough it seems:

7) Failure:
test_segv_test(TestRubyOptions) [/builddir/build/BUILD/ruby-2.0.0-p247/test/ruby/test_rubyoptions.rb:513]:
Expected /#'\n-e:3:in `kill'\n\n-- C level backtrace information -------------------------------------------\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x176968) [0xf07968] vm_dump.c:647\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x5826d) [0xde926d] error.c:283\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(rb_bug+0x40) [0xde9680] error.c:302\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x108b4d) [0xe99b4d] signal.c:672\n[0x2e4410]\n[0x2e4430]\n/lib/libc.so.6(kill+0x16) [0x313c46]\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(rb_f_kill+0x5e) [0xe9a59e] signal.c:424\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x15b60e) [0xeec60e] vm_insnhelper.c:1325\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x160013) [0xef1013] vm_insnhelper.c:1469\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x171cf7) [0xf02cf7] vm_insnhelper.c:1559\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x164625) [0xef5625] insns.def:1017\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x169d96) [0xefad96] vm.c:1201\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(rb_iseq_eval_main+0x8b) [0xefcd2b] vm.c:1449\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(+0x5b3cc) [0xdec3cc] eval.c:250\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(ruby_exec_node+0x24) [0xdedbd4] eval.c:315\n/builddir/build/BUILD/ruby-2.0.0-p247/libruby.so.2.0.0(ruby_run_node+0x30) [0xdef6b0] eval.c:307\n/builddir/build/BUILD/ruby-2.0.0-p247/ruby() [0x80486b8] main.c:36\n/lib/libc.so.6(__libc_start_main+0xf3) [0x2fe933]\n/builddir/build/BUILD/ruby-2.0.0-p247/ruby() [0x80486e1] main.c:38\n\n-- Other runtime information -----------------------------------------------\n\n* Loaded script: -e\n\n* Loaded features:\n\n".
13262 tests, 2234484 assertions, 1 failures, 0 errors, 34 skips
ruby -v: ruby 2.0.0p247 (2013-06-27) [i386-linux]
make: *** [yes-test-all] Error 1
=end

Also available in: Atom PDF