Bug #18257: rb_mRubyVMFrozenCore is broken by GC run

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 3.0.3p157 (2021-11-24 revision 3fb7d2cadc) [x86_64-linux]
• Backport: 3.0: REQUIRED, 3.1: REQUIRED, 3.2: REQUIRED

[vo.x (Vit Ondruch)]

Testing Ruby with SystemTap on RHEL9 beta following these steps:

$ stap -v /usr/share/doc/ruby-doc/ruby-exercise.stp &
$ ruby -e '[1, 2, 3].push(4)'

I get the following error:

/usr/share/rubygems/rubygems/errors.rb:181: [BUG] Segmentation fault at 0x0000000000000014
ruby 3.0.2p107 (2021-07-07 revision 0db68f0233) [powerpc64le-linux]

-- Control frame information -----------------------------------------------
c:0008 p:0028 s:0032 e:000027 CLASS  /usr/share/rubygems/rubygems/errors.rb:181
c:0007 p:0110 s:0025 e:000024 CLASS  /usr/share/rubygems/rubygems/errors.rb:153
c:0006 p:0007 s:0022 e:000021 TOP    /usr/share/rubygems/rubygems/errors.rb:9 [FINISH]
c:0005 p:---- s:0019 e:000018 CFUNC  :require
c:0004 p:0037 s:0014 e:000013 TOP    /usr/share/rubygems/rubygems.rb:19 [FINISH]
c:0003 p:---- s:0011 e:000010 CFUNC  :require
c:0002 p:0012 s:0006 e:000005 TOP    <internal:gem_prelude>:2 [FINISH]
c:0001 p:0000 s:0003 E:0026c0 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
<internal:gem_prelude>:2:in `<internal:gem_prelude>'
<internal:gem_prelude>:2:in `require'
/usr/share/rubygems/rubygems.rb:19:in `<top (required)>'
/usr/share/rubygems/rubygems.rb:19:in `require'
/usr/share/rubygems/rubygems/errors.rb:9:in `<top (required)>'
/usr/share/rubygems/rubygems/errors.rb:153:in `<module:Gem>'
/usr/share/rubygems/rubygems/errors.rb:181:in `<class:SourceFetchProblem>'

-- C level backtrace information -------------------------------------------
/lib64/libruby.so.3.0(0x7fffb3b06ba0) [0x7fffb3b06ba0]
/lib64/libruby.so.3.0(0x7fffb38d9680) [0x7fffb38d9680]
/lib64/libruby.so.3.0(0x7fffb3a4b9d8) [0x7fffb3a4b9d8]
linux-vdso64.so.1(__kernel_sigtramp_rt64+0x0) [0x7fffb3ca0464]
[0x7fffb3a67ff8]
/lib64/libruby.so.3.0(rb_str_dup+0x130) [0x7fffb3a6b950]
/lib64/libruby.so.3.0(rb_class_path+0x3c) [0x7fffb3ac72ac]
/lib64/libruby.so.3.0(rb_dtrace_setup+0x134) [0x7fffb3ae46a4]
[0x7fffb3ae4a00]
[0x7fffb3ae7644]
[0x7fffb3aeba5c]
/lib64/libruby.so.3.0(rb_vm_exec+0x140) [0x7fffb3af1710]
/lib64/libruby.so.3.0(rb_iseq_eval+0x164) [0x7fffb3af29f4]
[0x7fffb394ce68]
/lib64/libruby.so.3.0(rb_require_string+0x44) [0x7fffb394e7f4]
/lib64/libruby.so.3.0(rb_f_require+0x1c) [0x7fffb394e88c]
[0x7fffb3acf538]
[0x7fffb3ae4900]
[0x7fffb3ae7644]
[0x7fffb3aeba5c]
/lib64/libruby.so.3.0(rb_vm_exec+0x140) [0x7fffb3af1710]
/lib64/libruby.so.3.0(rb_iseq_eval+0x164) [0x7fffb3af29f4]
[0x7fffb394ce68]
/lib64/libruby.so.3.0(rb_require_string+0x44) [0x7fffb394e7f4]
/lib64/libruby.so.3.0(rb_f_require+0x1c) [0x7fffb394e88c]
[0x7fffb3acf538]
[0x7fffb3ae4900]
[0x7fffb3ae7644]
[0x7fffb3aeba5c]
/lib64/libruby.so.3.0(rb_vm_exec+0x140) [0x7fffb3af1710]
/lib64/libruby.so.3.0(rb_iseq_eval+0x164) [0x7fffb3af29f4]
[0x7fffb3b15f60]
[0x7fffb3a4826c]
[0x7fffb3a499d8]
/lib64/libruby.so.3.0(ruby_process_options+0x158) [0x7fffb3a4a778]
/lib64/libruby.so.3.0(ruby_options+0xf4) [0x7fffb38e5904]
[0x11a360a60]
[0x7fffb35d7ca4]
[0x7fffb35d7e80]

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

* Loaded script: ruby

* Loaded features:

    0 enumerator.so
    1 thread.rb
    2 rational.so
    3 complex.so
    4 ruby2_keywords.rb
    5 /usr/lib64/ruby/enc/encdb.so
    6 /usr/lib64/ruby/enc/trans/transdb.so
    7 /usr/lib64/ruby/rbconfig.rb
    8 /usr/share/rubygems/rubygems/compatibility.rb
    9 /usr/share/rubygems/rubygems/defaults.rb
   10 /usr/share/rubygems/rubygems/deprecate.rb

* Process memory map:

11a360000-11a370000 r-xp 00000000 fd:00 34097694                         /usr/bin/ruby
11a370000-11a380000 r--p 00000000 fd:00 34097694                         /usr/bin/ruby
11a380000-11a390000 rw-p 00010000 fd:00 34097694                         /usr/bin/ruby
1000d490000-1000d6b0000 rw-p 00000000 00:00 0                            [heap]
7fffaf470000-7fffaf8d0000 r--s 00000000 fd:00 67811909                   /usr/lib64/libruby.so.3.0.2
7fffaf8d0000-7fffaf8f0000 r--s 00000000 fd:00 34097694                   /usr/bin/ruby
7fffaf8f0000-7fffaf900000 r-xp 00000000 fd:00 100999014                  /usr/lib64/ruby/enc/trans/transdb.so
7fffaf900000-7fffaf910000 r--p 00000000 fd:00 100999014                  /usr/lib64/ruby/enc/trans/transdb.so
7fffaf910000-7fffaf920000 rw-p 00000000 00:00 0 
7fffaf920000-7fffaf930000 r-xp 00000000 fd:00 67811915                   /usr/lib64/ruby/enc/encdb.so
7fffaf930000-7fffaf940000 r--p 00000000 fd:00 67811915                   /usr/lib64/ruby/enc/encdb.so
7fffaf940000-7fffaf950000 rw-p 00000000 00:00 0 
7fffaf950000-7fffaf960000 ---p 00000000 00:00 0 
7fffaf960000-7fffafa10000 rw-p 00000000 00:00 0 
7fffafa10000-7fffafa20000 ---p 00000000 00:00 0 
7fffafa20000-7fffafad0000 rw-p 00000000 00:00 0 
7fffafad0000-7fffafae0000 ---p 00000000 00:00 0 
7fffafae0000-7fffafb90000 rw-p 00000000 00:00 0 
7fffafb90000-7fffafba0000 ---p 00000000 00:00 0 
7fffafba0000-7fffafc50000 rw-p 00000000 00:00 0 
7fffafc50000-7fffafc60000 ---p 00000000 00:00 0 
7fffafc60000-7fffafd10000 rw-p 00000000 00:00 0 
7fffafd10000-7fffafd20000 ---p 00000000 00:00 0 
7fffafd20000-7fffafdd0000 rw-p 00000000 00:00 0 
7fffafdd0000-7fffafde0000 ---p 00000000 00:00 0 
7fffafde0000-7fffafe90000 rw-p 00000000 00:00 0 
7fffafe90000-7fffafea0000 ---p 00000000 00:00 0 
7fffafea0000-7fffaff50000 rw-p 00000000 00:00 0 
7fffaff50000-7fffaff60000 ---p 00000000 00:00 0 
7fffaff60000-7fffb0010000 rw-p 00000000 00:00 0 
7fffb0010000-7fffb0020000 ---p 00000000 00:00 0 
7fffb0020000-7fffb00d0000 rw-p 00000000 00:00 0 
7fffb00d0000-7fffb00e0000 ---p 00000000 00:00 0 
7fffb00e0000-7fffb0190000 rw-p 00000000 00:00 0 
7fffb0190000-7fffb01a0000 ---p 00000000 00:00 0 
7fffb01a0000-7fffb0250000 rw-p 00000000 00:00 0 
7fffb0250000-7fffb0260000 ---p 00000000 00:00 0 
7fffb0260000-7fffb0310000 rw-p 00000000 00:00 0 
7fffb0310000-7fffb0320000 ---p 00000000 00:00 0 
7fffb0320000-7fffb03d0000 rw-p 00000000 00:00 0 
7fffb03d0000-7fffb03e0000 ---p 00000000 00:00 0 
7fffb03e0000-7fffb0490000 rw-p 00000000 00:00 0 
7fffb0490000-7fffb04a0000 ---p 00000000 00:00 0 
7fffb04a0000-7fffb0550000 rw-p 00000000 00:00 0 
7fffb0550000-7fffb0560000 ---p 00000000 00:00 0 
7fffb0560000-7fffb0610000 rw-p 00000000 00:00 0 
7fffb0610000-7fffb0620000 ---p 00000000 00:00 0 
7fffb0620000-7fffb06d0000 rw-p 00000000 00:00 0 
7fffb06d0000-7fffb06e0000 ---p 00000000 00:00 0 
7fffb06e0000-7fffb0790000 rw-p 00000000 00:00 0 
7fffb0790000-7fffb07a0000 ---p 00000000 00:00 0 
7fffb07a0000-7fffb0850000 rw-p 00000000 00:00 0 
7fffb0850000-7fffb0860000 ---p 00000000 00:00 0 
7fffb0860000-7fffb0910000 rw-p 00000000 00:00 0 
7fffb0910000-7fffb0920000 ---p 00000000 00:00 0 
7fffb0920000-7fffb09d0000 rw-p 00000000 00:00 0 
7fffb09d0000-7fffb09e0000 ---p 00000000 00:00 0 
7fffb09e0000-7fffb0a90000 rw-p 00000000 00:00 0 
7fffb0a90000-7fffb0aa0000 ---p 00000000 00:00 0 
7fffb0aa0000-7fffb0b50000 rw-p 00000000 00:00 0 
7fffb0b50000-7fffb0b60000 ---p 00000000 00:00 0 
7fffb0b60000-7fffb0c10000 rw-p 00000000 00:00 0 
7fffb0c10000-7fffb0c20000 ---p 00000000 00:00 0 
7fffb0c20000-7fffb0cd0000 rw-p 00000000 00:00 0 
7fffb0cd0000-7fffb0ce0000 ---p 00000000 00:00 0 
7fffb0ce0000-7fffb0d90000 rw-p 00000000 00:00 0 
7fffb0d90000-7fffb0da0000 ---p 00000000 00:00 0 
7fffb0da0000-7fffb0e50000 rw-p 00000000 00:00 0 
7fffb0e50000-7fffb0e60000 ---p 00000000 00:00 0 
7fffb0e60000-7fffb0f10000 rw-p 00000000 00:00 0 
7fffb0f10000-7fffb0f20000 ---p 00000000 00:00 0 
7fffb0f20000-7fffb0fd0000 rw-p 00000000 00:00 0 
7fffb0fd0000-7fffb0fe0000 ---p 00000000 00:00 0 
7fffb0fe0000-7fffb1090000 rw-p 00000000 00:00 0 
7fffb1090000-7fffb10a0000 ---p 00000000 00:00 0 
7fffb10a0000-7fffb32e0000 rw-p 00000000 00:00 0 
7fffb32e0000-7fffb3340000 r--p 00000000 fd:00 33555845                   /usr/lib/locale/en_US.utf8/LC_CTYPE
7fffb3340000-7fffb3420000 r-xp 00000000 fd:00 67172714                   /usr/lib64/libm.so.6
7fffb3420000-7fffb3430000 r--p 000d0000 fd:00 67172714                   /usr/lib64/libm.so.6
7fffb3430000-7fffb3440000 rw-p 000e0000 fd:00 67172714                   /usr/lib64/libm.so.6
7fffb3440000-7fffb3480000 r-xp 00000000 fd:00 67172871                   /usr/lib64/libcrypt.so.2.0.0
7fffb3480000-7fffb3490000 r--p 00030000 fd:00 67172871                   /usr/lib64/libcrypt.so.2.0.0
7fffb3490000-7fffb34a0000 rw-p 00000000 00:00 0 
7fffb34a0000-7fffb3540000 r-xp 00000000 fd:00 67172912                   /usr/lib64/libgmp.so.10.4.0
7fffb3540000-7fffb3550000 r--p 00090000 fd:00 67172912                   /usr/lib64/libgmp.so.10.4.0
7fffb3550000-7fffb3560000 rw-p 000a0000 fd:00 67172912                   /usr/lib64/libgmp.so.10.4.0
7fffb3560000-7fffb3580000 r-xp 00000000 fd:00 67172832                   /usr/lib64/libz.so.1.2.11
7fffb3580000-7fffb3590000 r--p 00010000 fd:00 67172832                   /usr/lib64/libz.so.1.2.11
7fffb3590000-7fffb35a0000 rw-p 00020000 fd:00 67172832                   /usr/lib64/libz.so.1.2.11
7fffb35a0000-7fffb37e0000 r-xp 00000000 fd:00 67172711                   /usr/lib64/libc.so.6
7fffb37e0000-7fffb37f0000 r--p 00230000 fd:00 67172711                   /usr/lib64/libc.so.6
7fffb37f0000-7fffb3800000 rw-p 00240000 fd:00 67172711                   /usr/lib64/libc.so.6
7fffb3800000-7fffb3c30000 r-xp 00000000 fd:00 67811909                   /usr/lib64/libruby.so.3.0.2
7fffb3c30000-7fffb3c40000 ---p 00430000 fd:00 67811909                   /usr/lib64/libruby.so.3.0.2
7fffb3c40000-7fffb3c50000 r--p 00430000 fd:00 67811909                   /usr/lib64/libruby.so.3.0.2
7fffb3c50000-7fffb3c60000 rw-p 00440000 fd:00 67811909                   /usr/lib64/libruby.so.3.0.2
7fffb3c60000-7fffb3c70000 rw-p 00000000 00:00 0 
7fffb3c70000-7fffb3c80000 r--s 00000000 fd:00 100673889                  /usr/lib64/gconv/gconv-modules.cache
7fffb3c80000-7fffb3ca0000 r--p 00000000 00:00 0                          [vvar]
7fffb3ca0000-7fffb3cb0000 r-xp 00000000 00:00 0                          [vdso]
7fffb3cb0000-7fffb3d00000 r-xp 00000000 fd:00 67172707                   /usr/lib64/ld64.so.2
7fffb3d00000-7fffb3d10000 r--p 00040000 fd:00 67172707                   /usr/lib64/ld64.so.2
7fffb3d10000-7fffb3d20000 rw-p 00050000 fd:00 67172707                   /usr/lib64/ld64.so.2
7fffdee00000-7fffdf600000 rw-p 00000000 00:00 0                          [stack]

This should be the full BT:

(gdb) bt
#0  0x00007fffa5711550 in uleb128 (p=0x10039917f10) at addr2line.c:200
#1  di_read_die (reader=reader@entry=0x10039917eb8, die=die@entry=0x10039917dc8) at addr2line.c:1343
#2  0x00007fffa5714574 in debug_info_read (offset=<optimized out>, lines=<optimized out>, traces=<optimized out>, num_traces=<optimized out>, reader=<optimized out>) at addr2line.c:1630
#3  fill_lines (num_traces=num_traces@entry=39, traces=traces@entry=0x7fffa585d778 <trace>, check_debuglink=check_debuglink@entry=0, objp=objp@entry=0x10039919370, lines=lines@entry=0x100399756f0, 
    offset=<optimized out>, offset@entry=0) at addr2line.c:1887
#4  0x00007fffa5714f28 in follow_debuglink (offset=0, lines=0x100399756f0, objp=0x10039919370, traces=<optimized out>, num_traces=39, debuglink=0x7fffa14e01e4 "ruby-3.0.2-155.el9.ppc64le.debug")
    at addr2line.c:574
#5  fill_lines (num_traces=num_traces@entry=39, traces=traces@entry=0x7fffa585d778 <trace>, check_debuglink=check_debuglink@entry=1, objp=0x10039919370, objp@entry=0x100399193f0, 
    lines=lines@entry=0x100399756f0, offset=<optimized out>, offset@entry=-1) at addr2line.c:1925
#6  0x00007fffa571576c in rb_dump_backtrace_with_lines (num_traces=<optimized out>, traces=0x7fffa585d778 <trace>) at addr2line.c:2286
#7  0x00007fffa5706bac in rb_print_backtrace () at vm_dump.c:760
#8  rb_vm_bugreport (ctx=<optimized out>) at vm_dump.c:998
#9  0x00007fffa54d9680 in rb_bug_for_fatal_signal (default_sighandler=0x0, sig=<optimized out>, ctx=0x100399197c0, fmt=0x7fffa574e8f0 "Segmentation fault at %p") at error.c:786
#10 0x00007fffa564b9d8 in sigsegv (sig=<optimized out>, info=0x1003991a540, ctx=0x100399197c0) at signal.c:960
#11 <signal handler called>
#12 0x00007fffa5667ff8 in str_new_frozen_buffer (klass=klass@entry=1100477014720, orig=orig@entry=1100476844400, copy_encoding=copy_encoding@entry=1) at string.c:1329
#13 0x00007fffa566b950 in str_new_frozen (orig=1100476844400, klass=1100477014720) at string.c:1297
#14 str_duplicate_setup (dup=1100478149120, str=1100476844400, klass=1100477014720) at string.c:1570
#15 str_duplicate (str=1100476844400, klass=1100477014720) at string.c:1602
#16 rb_str_dup (str=1100476844400) at string.c:1608
#17 0x00007fffa56c72ac in rb_class_path (klass=1100476844480) at variable.c:173
#18 0x00007fffa56e46a4 in rb_dtrace_setup (ec=<optimized out>, klass=1100476844480, id=159, args=0x7fffe9d953d8) at vm.c:449
#19 0x00007fffa56e4a00 in vm_call_cfunc_with_frame (ec=<optimized out>, reg_cfp=0x7fffa4ecfe50, calling=<optimized out>) at vm_insnhelper.c:2916
#20 0x00007fffa56e7644 in vm_sendish (ec=0x10039811cf0, reg_cfp=0x7fffa4ecfe50, cd=0x100399a8db0, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#21 0x00007fffa56eba5c in vm_exec_core (ec=0x10039811cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#22 0x00007fffa56f1710 in rb_vm_exec (ec=0x10039811cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#23 0x00007fffa56f29f4 in rb_iseq_eval (iseq=0x100398aa7c0) at vm.c:2409
#24 0x00007fffa554ce68 in load_iseq_eval (fname=1100477137480, ec=0x10039811cf0) at load.c:594
#25 require_internal (ec=ec@entry=0x10039811cf0, fname=<optimized out>, fname@entry=1100476430040, exception=exception@entry=1) at load.c:1065
#26 0x00007fffa554e7f4 in rb_require_string (fname=1100476430040) at load.c:1142
#27 0x00007fffa554e88c in rb_f_require (obj=<optimized out>, fname=<optimized out>) at load.c:838
#28 0x00007fffa56cf538 in ractor_safe_call_cfunc_1 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2750
#29 0x00007fffa56e4900 in vm_call_cfunc_with_frame (ec=0x10039811cf0, reg_cfp=0x7fffa4ecff30, calling=<optimized out>) at vm_insnhelper.c:2926
#30 0x00007fffa56e7644 in vm_sendish (ec=0x10039811cf0, reg_cfp=0x7fffa4ecff30, cd=0x10039901e50, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#31 0x00007fffa56eba5c in vm_exec_core (ec=0x10039811cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#32 0x00007fffa56f1710 in rb_vm_exec (ec=0x10039811cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#33 0x00007fffa56f29f4 in rb_iseq_eval (iseq=0x1003981b9a8) at vm.c:2409
#34 0x00007fffa554ce68 in load_iseq_eval (fname=1100476613760, ec=0x10039811cf0) at load.c:594
#35 require_internal (ec=ec@entry=0x10039811cf0, fname=<optimized out>, fname@entry=1100476614040, exception=exception@entry=1) at load.c:1065
#36 0x00007fffa554e7f4 in rb_require_string (fname=1100476614040) at load.c:1142
#37 0x00007fffa554e88c in rb_f_require (obj=<optimized out>, fname=<optimized out>) at load.c:838
#38 0x00007fffa56cf538 in ractor_safe_call_cfunc_1 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2750
#39 0x00007fffa56e4900 in vm_call_cfunc_with_frame (ec=0x10039811cf0, reg_cfp=0x7fffa4ecffa0, calling=<optimized out>) at vm_insnhelper.c:2926
#40 0x00007fffa56e7644 in vm_sendish (ec=0x10039811cf0, reg_cfp=0x7fffa4ecffa0, cd=0x10039970580, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#41 0x00007fffa56eba5c in vm_exec_core (ec=0x10039811cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#42 0x00007fffa56f1710 in rb_vm_exec (ec=0x10039811cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#43 0x00007fffa56f29f4 in rb_iseq_eval (iseq=0x100398489f8) at vm.c:2409
#44 0x00007fffa5715f60 in rb_load_with_builtin_functions (feature_name=0x7fffa57b61c0 "gem_prelude", table=0x0) at builtin.c:54
#45 0x00007fffa564826c in ruby_init_prelude () at ruby.c:1498
#46 ruby_opt_init (opt=0x7fffe9d98690) at ruby.c:1521
#47 ruby_opt_init (opt=0x7fffe9d98690) at ruby.c:1506
#48 0x00007fffa56499d8 in process_options (argc=0, argc@entry=3, argv=0x7fffe9d98f10, argv@entry=0x7fffe9d98ef8, opt=opt@entry=0x7fffe9d98690) at ruby.c:1951
#49 0x00007fffa564a778 in ruby_process_options (argc=<optimized out>, argv=0x7fffe9d98ef8) at ruby.c:230
#50 0x00007fffa54e5904 in ruby_options (argc=<optimized out>, argv=0x7fffe9d98ef8) at eval.c:138
#51 0x000000010b860a60 in main (argc=<optimized out>, argv=<optimized out>) at ./main.c:50

[vo.x (Vit Ondruch)]

My guess is that this is not really platform dependent, but instead, this is GC and it exhibits on different platforms just due to different memory layout. I think the issue is that the DTrace probe is trying to access some information which was previously swept by GC. This limits the issue in this simple example it seems:

$ RUBY_GC_HEAP_INIT_SLOTS=100000 ruby -e '[1, 2, 3].push(4)'

Using two ssh sessions, I have now noticed that there are also quite some messages such as the following reported:

RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.

[vo.x (Vit Ondruch)]

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7d47ff8 in str_new_frozen_buffer (klass=klass@entry=4295795400, orig=orig@entry=4295625080, copy_encoding=copy_encoding@entry=1) at string.c:1329
1329		else if (STR_EMBEDDABLE_P(RSTRING_LEN(orig), TERM_LEN(orig))) {
(gdb) p (*(struct RString *)(orig))
$1 = {basic = {flags = 73831, klass = 4295795400}, as = {heap = {len = 4295436520, ptr = 0x100072870 "e\bS ", aux = {capa = 0, shared = 0}}, 
    ary = "\350(\a\000\001\000\000\000p(\a\000\001\000\000\000\000\000\000\000\000\000\000"}}

Not sure this is helpful ...

[nobu (Nobuyoshi Nakada)]

vo.x (Vit Ondruch) wrote in #note-2:

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7d47ff8 in str_new_frozen_buffer (klass=klass@entry=4295795400, orig=orig@entry=4295625080, copy_encoding=copy_encoding@entry=1) at string.c:1329
1329		else if (STR_EMBEDDABLE_P(RSTRING_LEN(orig), TERM_LEN(orig))) {
(gdb) p (*(struct RString *)(orig))
$1 = {basic = {flags = 73831, klass = 4295795400}, as = {heap = {len = 4295436520, ptr = 0x100072870 "e\bS ", aux = {capa = 0, shared = 0}}, 
    ary = "\350(\a\000\001\000\000\000p(\a\000\001\000\000\000\000\000\000\000\000\000\000"}}

Not sure this is helpful ...

The flags 73831 = 0x12067, that means orig is an Array object, which has two elements(0x00000001000728e8, 0x0000000100072870).

[nobu (Nobuyoshi Nakada)]

I think a condition of "RSTRING_PTR is returning NULL!!" was fixed this year, but can't remember now.

[vo.x (Vit Ondruch)]

nobu (Nobuyoshi Nakada) wrote in #note-3:

vo.x (Vit Ondruch) wrote in #note-2:

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7d47ff8 in str_new_frozen_buffer (klass=klass@entry=4295795400, orig=orig@entry=4295625080, copy_encoding=copy_encoding@entry=1) at string.c:1329
1329		else if (STR_EMBEDDABLE_P(RSTRING_LEN(orig), TERM_LEN(orig))) {
(gdb) p (*(struct RString *)(orig))
$1 = {basic = {flags = 73831, klass = 4295795400}, as = {heap = {len = 4295436520, ptr = 0x100072870 "e\bS ", aux = {capa = 0, shared = 0}}, 
    ary = "\350(\a\000\001\000\000\000p(\a\000\001\000\000\000\000\000\000\000\000\000\000"}}

Not sure this is helpful ...

The flags 73831 = 0x12067, that means orig is an Array object, which has two elements(0x00000001000728e8, 0x0000000100072870).

If that was array, then this is the output:

(gdb) p (*(struct RArray *)(orig))
$3 = {basic = {flags = 73831, klass = 4295795400}, as = {heap = {len = 4295436520, aux = {capa = 4295436400, shared_root = 4295436400}, ptr = 0x0}, ary = {4295436520, 4295436400, 0}}}

(gdb) call ruby_debug_print_v(orig)
DBG> : 0x00000001000a0978 [3LM   ] T_ARRAY (Array)[E ] len: 2 (embed)

(gdb) call ruby_debug_print_v((*(struct RArray *)(orig))->as->ary[0])
DBG> : 0x00000001000728e8 [3LM   ] T_STRING (String)Ruby

(gdb) call ruby_debug_print_v((*(struct RArray *)(orig))->as->ary[1])
DBG> : 0x0000000100072870 [3LM   ] T_STRING (String)BSD-2-Clause

But why it should be array on such place? Isn't it the crux of the problem? Can rb_tmp_class_path 1 return array?

Just FTR, there is this RHEL8 ticket 2 and it seems there is certainly something fishy with the SystemTap/DTrace probes, because they can report some random strings.

[vo.x (Vit Ondruch)]

Interestingly, the error exhibits on two palces as far as I can tell:

https://github.com/ruby/ruby/blob/v3_0_2/lib/rubygems/errors.rb#L181
https://github.com/ruby/ruby/blob/0db68f023372b634603c74fca94588b457be084c/ext/monitor/lib/monitor.rb#L165

The error.rb corresponds with the original report, while the other place is monitor.rb. What is interesting is that both places try to setup aliases.

[vo.x (Vit Ondruch)]

So the array comes via this path:

https://github.com/ruby/ruby/blob/0db68f023372b634603c74fca94588b457be084c/variable.c#L172
https://github.com/ruby/ruby/blob/0db68f023372b634603c74fca94588b457be084c/variable.c#L148
https://github.com/ruby/ruby/blob/0db68f023372b634603c74fca94588b457be084c/variable.c#L102

And these are the variables:

(gdb) call ruby_debug_print_v(klass)
DBG> : 0x00000001000a09c8 [3LM   ] T_ICLASS

(gdb) call ruby_debug_print_v(n)
DBG> : 0x00000001000a0978 [3LM   ] T_ARRAY (Array)[E ] len: 2 (embed)

[vo.x (Vit Ondruch)]

This is the status right before the hook is called:

#0  vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75afe18, calling=0x7fffffffa790) at vm_insnhelper.c:2916
2916	    RUBY_DTRACE_CMETHOD_ENTRY_HOOK(ec, me->owner, me->def->original_id);
(gdb) call ruby_debug_print_v(me)
DBG> : 0x00000001000a0928 [3LM   ] T_IMEMO <ment> :core#set_method_alias (pub,cc) type:cfunc alias:0 owner:0x00000001000a0950 defined_class:0x00000001000a0950
(gdb) call ruby_debug_print_v(me->owner)
DBG> : 0x00000001000a0950 [3LM   ] T_CLASS (annon)

And here the klass changes:

#0  rb_dtrace_setup (ec=<optimized out>, klass=4295625040, id=159, args=0x7fffffffa678) at vm.c:444
444		klass = rb_attr_get(klass, id__attached__);
(gdb) l
439	    }
440	    if (RB_TYPE_P(klass, T_ICLASS)) {
441		klass = RBASIC(klass)->klass;
442	    }
443	    else if (FL_TEST(klass, FL_SINGLETON)) {
444		klass = rb_attr_get(klass, id__attached__);
445		if (NIL_P(klass)) return FALSE;
446	    }
447	    type = BUILTIN_TYPE(klass);
448	    if (type == T_CLASS || type == T_ICLASS || type == T_MODULE) {
(gdb) n
445		if (NIL_P(klass)) return FALSE;
(gdb) call ruby_debug_print_v(klass)
DBG> : 0x00000001000a09c8 [3LM   ] T_ICLASS 

I am not sure I understand what the rb_attr_get(klass, id__attached__) actually does. Originally 1, there used to be used just rb_class2name which would work for this case:

(gdb) call rb_class2name(klass)
$44 = 0x1000f28f0 "BasicObject"

[vo.x (Vit Ondruch)]

• Subject changed from SystemTap/DTrace coredump on ppc64le/s390x to SystemTap/DTrace coredump
• ruby -v changed from ruby 3.0.2p107 (2021-07-07 revision 0db68f0233) [powerpc64le-linux] to ruby 3.0.3p157 (2021-11-24 revision 3fb7d2cadc) [x86_64-linux]

It is actually reproducible everywhere. I was able to reproduce it on x86_64 although it fails less frequently.

[vo.x (Vit Ondruch)]

So the TracePoint API must use similar paths. Therefore, looking at vm_trace.c, I have noticed this 1 line:

trace_arg->self != rb_mRubyVMFrozenCore /* skip special methods. TODO: remove it. */) {

I have traced their origin to this 2 commit, but unfortunately, it does not provide any answer. What does it protect against? I am asking, because RubyVM::FrozenCore was mentioned in this 3 SystemTap comment and I don't see check like this in the rb_dtrace_setup (while there are certainly quite some checks).

[vo.x (Vit Ondruch)]

I have confirmed that the rb_mRubyVMFrozenCore is the problematic class. It seems it gets corrupted during GC cycle. If lucky, their cached classpath is still String, which is ... well, String. But sometimes, it is e.g. Array instead and that is kind of problematic for rb_str_dup to duplicate.

[vo.x (Vit Ondruch)]

Some snippets from my debugging. Initially, I set the breakpoint to the place where the rb_mRubyVMFrozenCore is assigned:

(gdb) b vm.c:3388
No source file named vm.c.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (vm.c:3388) pending.
(gdb) r
Starting program: /usr/bin/ruby -e ''
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".

Breakpoint 1, Init_VM () at vm.c:3388
3388	    rb_mRubyVMFrozenCore = fcore;
Missing separate debuginfos, use: dnf debuginfo-install glibc-2.34-21.el9.ppc64le gmp-6.2.0-10.el9.ppc64le libxcrypt-4.4.18-3.el9.ppc64le zlib-1.2.11-31.el9.ppc64le
(gdb) n
3394	    mjit = rb_define_module_under(rb_cRubyVM, "MJIT");

Just for illustration, this is associated SystemTap output which confirms it happens quite early:

69244 obj.create Object :0
69244 obj.create fatal :0
69244 obj.create fatal :0
69244 obj.create Object :0
69244 obj.create ARGF.class :0
69244 obj.create SystemStackError :0
69244 obj.create NoMemoryError :0

Lets try to collect some information:

(gdb) call ruby_debug_print_v(rb_mRubyVMFrozenCore)
DBG> : 0x00000001000a09c8 [0     ] T_ICLASS 
(gdb) p *(*(struct RClass *)(rb_mRubyVMFrozenCore))->ptr.iv_tbl.entries
$1 = {hash = 30421, key = 3809, record = 4295625080}
(gdb) call ruby_debug_print_v(4295625080)
DBG> : 0x00000001000a0978 [0     ] T_STRING (String)RubyVM::FrozenCore
(gdb) p *(struct RString *)(4295625080)
$2 = {basic = {flags = 8685573, klass = 4295927560}, as = {heap = {len = 4195751036648060242, ptr = 0x6f436e657a6f7246 <error: Cannot access memory at address 0x6f436e657a6f7246>, aux = {capa = 25970, 
        shared = 25970}}, ary = "RubyVM::FrozenCore\000\000\000\000\000"}}

The *(*(struct RClass *)(rb_mRubyVMFrozenCore))->ptr.iv_tbl.entries seems to link to a RubyVM::FrozenCore string which seem to be reasonable. In ideal state, these values should be static, during the whole Ruby instance lifetime, right? But I suspect they change somehow, so lets try to setup some watch:

(gdb) watch ((struct RBasic *)(4295625080))->klass
Watchpoint 2: ((struct RBasic *)(4295625080))->klass
(gdb) c
Continuing.

And indeed, the breakpoint is triggered:

Old value = 4295927560
New value = 4295624320
heap_page_add_freeobj (obj=4295625080, page=0x100036d40, objspace=<optimized out>) at gc.c:1701
1701	    page->freelist = p;
(gdb) bt
#0  heap_page_add_freeobj (obj=4295625080, page=0x100036d40, objspace=<optimized out>) at gc.c:1701
#1  gc_page_sweep (sweep_page=0x100036d40, heap=0x100031658, objspace=<optimized out>) at gc.c:4923
#2  gc_sweep_step (objspace=objspace@entry=0x100031630, heap=heap@entry=0x100031658) at gc.c:5134
#3  0x00007ffff7bed128 in gc_sweep_continue (heap=<optimized out>, objspace=0x100031630) at gc.c:5202
#4  heap_prepare (heap=<optimized out>, objspace=0x100031630) at gc.c:2041
#5  heap_next_freepage (heap=<optimized out>, objspace=<optimized out>) at gc.c:2200
#6  ractor_cache_slots (cr=<optimized out>, objspace=<optimized out>) at gc.c:2219
#7  newobj_slowpath (wb_protected=1, cr=0x1000357f0, objspace=0x100031630, flags=53274, klass=0) at gc.c:2265
#8  newobj_slowpath_wb_protected (klass=klass@entry=0, flags=flags@entry=53274, objspace=0x100031630, cr=0x1000357f0) at gc.c:2284
#9  0x00007ffff7bed784 in newobj_of0 (cr=<optimized out>, wb_protected=1, flags=53274, klass=0) at gc.c:2322
#10 newobj_of (wb_protected=1, v3=0, v2=0, v1=0, flags=53274, klass=0) at gc.c:2333
#11 rb_imemo_new (type=<optimized out>, v1=0, v2=0, v3=0, v0=0) at gc.c:2418
#12 0x00007ffff7dce0cc in vm_ic_update (reg_ep=<optimized out>, val=<optimized out>, ic=<optimized out>, iseq=<optimized out>) at vm_insnhelper.c:4669
#13 vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:1043
#14 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#15 0x00007ffff7dd29f4 in rb_iseq_eval (iseq=0x10004a410) at vm.c:2409
#16 0x00007ffff7c2ce68 in load_iseq_eval (fname=4295431320, ec=0x100031cf0) at load.c:594
#17 require_internal (ec=ec@entry=0x100031cf0, fname=<optimized out>, fname@entry=4295211000, exception=exception@entry=1) at load.c:1065
#18 0x00007ffff7c2e7f4 in rb_require_string (fname=4295211000) at load.c:1142
#19 0x00007ffff7c2e88c in rb_f_require (obj=<optimized out>, fname=<optimized out>) at load.c:838
#20 0x00007ffff7daf538 in ractor_safe_call_cfunc_1 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2750
#21 0x00007ffff7dc4900 in vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75aff30, calling=<optimized out>) at vm_insnhelper.c:2926
#22 0x00007ffff7dc7644 in vm_sendish (ec=0x100031cf0, reg_cfp=0x7ffff75aff30, cd=0x100121e10, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#23 0x00007ffff7dcba5c in vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#24 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#25 0x00007ffff7dd29f4 in rb_iseq_eval (iseq=0x10003b988) at vm.c:2409
#26 0x00007ffff7c2ce68 in load_iseq_eval (fname=4295394400, ec=0x100031cf0) at load.c:594
#27 require_internal (ec=ec@entry=0x100031cf0, fname=<optimized out>, fname@entry=4295394680, exception=exception@entry=1) at load.c:1065
#28 0x00007ffff7c2e7f4 in rb_require_string (fname=4295394680) at load.c:1142
#29 0x00007ffff7c2e88c in rb_f_require (obj=<optimized out>, fname=<optimized out>) at load.c:838
#30 0x00007ffff7daf538 in ractor_safe_call_cfunc_1 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2750
#31 0x00007ffff7dc4900 in vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75affa0, calling=<optimized out>) at vm_insnhelper.c:2926
#32 0x00007ffff7dc7644 in vm_sendish (ec=0x100031cf0, reg_cfp=0x7ffff75affa0, cd=0x100190580, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#33 0x00007ffff7dcba5c in vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#34 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#35 0x00007ffff7dd29f4 in rb_iseq_eval (iseq=0x1000689d8) at vm.c:2409
#36 0x00007ffff7df5f60 in rb_load_with_builtin_functions (feature_name=0x7ffff7e961c0 "gem_prelude", table=0x0) at builtin.c:54
#37 0x00007ffff7d2826c in ruby_init_prelude () at ruby.c:1498
#38 ruby_opt_init (opt=0x7fffffffe5a0) at ruby.c:1521
#39 ruby_opt_init (opt=0x7fffffffe5a0) at ruby.c:1506
#40 0x00007ffff7d299d8 in process_options (argc=0, argc@entry=3, argv=0x7fffffffee20, argv@entry=0x7fffffffee08, opt=opt@entry=0x7fffffffe5a0) at ruby.c:1951
#41 0x00007ffff7d2a778 in ruby_process_options (argc=<optimized out>, argv=0x7fffffffee08) at ruby.c:230
#42 0x00007ffff7bc5904 in ruby_options (argc=<optimized out>, argv=0x7fffffffee08) at eval.c:138
#43 0x0000000100000a60 in main (argc=<optimized out>, argv=<optimized out>) at ./main.c:50

And here is the associated SystemTap log to give rough overview when this happened:

69244 obj.create Object <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 obj.create IOError <main>:0
69244 -> Exception::initialize <main>:0
69244 <- Exception::initialize <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 obj.create ThreadGroup <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited <main>:0
69244 <- Class::inherited <main>:0
69244 -> Class::inherited ruby:0
69244 <- Class::inherited ruby:0
69244 -> Class::inherited ruby:0
69244 <- Class::inherited ruby:0
69244 -> BasicObject::singleton_method_added <internal:gc>:33
69244 <- BasicObject::singleton_method_added <internal:gc>:33
69244 -> Module::method_added <internal:gc>:37
69244 <- Module::method_added <internal:gc>:37
69244 -> BasicObject::singleton_method_added <internal:gc>:46
69244 <- BasicObject::singleton_method_added <internal:gc>:46
69244 -> BasicObject::singleton_method_added <internal:gc>:58
69244 <- BasicObject::singleton_method_added <internal:gc>:58
69244 -> BasicObject::singleton_method_added <internal:gc>:72
69244 <- BasicObject::singleton_method_added <internal:gc>:72
69244 -> BasicObject::singleton_method_added <internal:gc>:84
69244 <- BasicObject::singleton_method_added <internal:gc>:84
69244 -> BasicObject::singleton_method_added <internal:gc>:92
69244 <- BasicObject::singleton_method_added <internal:gc>:92
69244 -> BasicObject::singleton_method_added <internal:gc>:110
69244 <- BasicObject::singleton_method_added <internal:gc>:110
69244 -> BasicObject::singleton_method_added <internal:gc>:120
69244 <- BasicObject::singleton_method_added <internal:gc>:120
69244 -> BasicObject::singleton_method_added <internal:gc>:169
69244 <- BasicObject::singleton_method_added <internal:gc>:169
69244 -> BasicObject::singleton_method_added <internal:gc>:183
69244 <- BasicObject::singleton_method_added <internal:gc>:183
69244 -> BasicObject::singleton_method_added <internal:gc>:197
69244 <- BasicObject::singleton_method_added <internal:gc>:197
69244 -> BasicObject::singleton_method_added <internal:gc>:212
69244 <- BasicObject::singleton_method_added <internal:gc>:212
69244 -> BasicObject::singleton_method_added <internal:gc>:230
69244 <- BasicObject::singleton_method_added <internal:gc>:230
69244 -> Module::method_added <internal:gc>:236
69244 <- Module::method_added <internal:gc>:236
69244 -> Module::module_function <internal:gc>:240
69244 -> BasicObject::singleton_method_added <internal:gc>:240
69244 <- BasicObject::singleton_method_added <internal:gc>:240
69244 <- Module::module_function <internal:gc>:240
69244 -> BasicObject::singleton_method_added <internal:ractor>:262
69244 <- BasicObject::singleton_method_added <internal:ractor>:262
69244 -> BasicObject::singleton_method_added <internal:ractor>:273
69244 <- BasicObject::singleton_method_added <internal:ractor>:273
69244 -> BasicObject::singleton_method_added <internal:ractor>:287
69244 <- BasicObject::singleton_method_added <internal:ractor>:287
69244 -> BasicObject::singleton_method_added <internal:ractor>:342
69244 <- BasicObject::singleton_method_added <internal:ractor>:342
69244 -> BasicObject::singleton_method_added <internal:ractor>:415
69244 <- BasicObject::singleton_method_added <internal:ractor>:415
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:422
69244 -> BasicObject::singleton_method_added <internal:ractor>:422
69244 <- BasicObject::singleton_method_added <internal:ractor>:422
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:422
69244 -> Module::method_added <internal:ractor>:426
69244 <- Module::method_added <internal:ractor>:426
69244 -> Module::private <internal:ractor>:426
69244 <- Module::private <internal:ractor>:426
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:431
69244 -> Module::method_added <internal:ractor>:431
69244 <- Module::method_added <internal:ractor>:431
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:431
69244 -> BasicObject::singleton_method_added <internal:ractor>:493
69244 <- BasicObject::singleton_method_added <internal:ractor>:493
69244 -> Module::method_added <internal:ractor>:497
69244 <- Module::method_added <internal:ractor>:497
69244 -> Module::private <internal:ractor>:497
69244 <- Module::private <internal:ractor>:497
69244 -> Module::method_added <internal:ractor>:582
69244 <- Module::method_added <internal:ractor>:582
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:587
69244 -> Module::method_added <internal:ractor>:587
69244 <- Module::method_added <internal:ractor>:587
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:587
69244 -> BasicObject::singleton_method_added <internal:ractor>:626
69244 <- BasicObject::singleton_method_added <internal:ractor>:626
69244 -> Module::method_added <internal:ractor>:693
69244 <- Module::method_added <internal:ractor>:693
69244 -> Module::method_added <internal:ractor>:699
69244 <- Module::method_added <internal:ractor>:699
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:709
69244 -> Module::method_added <internal:ractor>:709
69244 <- Module::method_added <internal:ractor>:709
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:ractor>:709
69244 -> Module::method_added <internal:ractor>:712
69244 <- Module::method_added <internal:ractor>:712
69244 -> Module::attr_reader <internal:ractor>:717
69244 -> Module::method_added <internal:ractor>:717
69244 <- Module::method_added <internal:ractor>:717
69244 <- Module::attr_reader <internal:ractor>:717
69244 -> Module::method_added <internal:ractor>:733
69244 <- Module::method_added <internal:ractor>:733
69244 -> Module::method_added <internal:ractor>:752
69244 <- Module::method_added <internal:ractor>:752
69244 -> BasicObject::singleton_method_added <internal:ractor>:769
69244 <- BasicObject::singleton_method_added <internal:ractor>:769
69244 -> BasicObject::singleton_method_added <internal:ractor>:810
69244 <- BasicObject::singleton_method_added <internal:ractor>:810
69244 -> Module::method_added <internal:ractor>:823
69244 <- Module::method_added <internal:ractor>:823
69244 -> Module::method_added <internal:ractor>:828
69244 <- Module::method_added <internal:ractor>:828
69244 -> BasicObject::singleton_method_added <internal:ractor>:833
69244 <- BasicObject::singleton_method_added <internal:ractor>:833
69244 -> Module::method_added <internal:integer>:6
69244 <- Module::method_added <internal:integer>:6
69244 -> Module::method_added <internal:integer>:22
69244 <- Module::method_added <internal:integer>:22
69244 -> Module::method_added <internal:integer>:27
69244 <- Module::method_added <internal:integer>:27
69244 -> Module::method_added <internal:integer>:73
69244 <- Module::method_added <internal:integer>:73
69244 -> Module::method_added <internal:integer>:82
69244 <- Module::method_added <internal:integer>:82
69244 -> Module::method_added <internal:integer>:91
69244 <- Module::method_added <internal:integer>:91
69244 -> Module::method_added <internal:integer>:95
69244 <- Module::method_added <internal:integer>:95
69244 -> Module::method_added <internal:integer>:104
69244 <- Module::method_added <internal:integer>:104
69244 -> Module::method_added <internal:integer>:120
69244 <- Module::method_added <internal:integer>:120
69244 -> Module::method_added <internal:integer>:130
69244 <- Module::method_added <internal:integer>:130
69244 -> Module::method_added <internal:integer>:138
69244 <- Module::method_added <internal:integer>:138
69244 -> Module::method_added <internal:integer>:146
69244 <- Module::method_added <internal:integer>:146
69244 -> Module::method_added <internal:io>:62
69244 <- Module::method_added <internal:io>:62
69244 -> Module::method_added <internal:io>:120
69244 <- Module::method_added <internal:io>:120
69244 -> BasicObject::singleton_method_added <internal:dir>:14
69244 <- BasicObject::singleton_method_added <internal:dir>:14
69244 -> Module::method_added <internal:dir>:34
69244 <- Module::method_added <internal:dir>:34
69244 -> BasicObject::singleton_method_added <internal:dir>:42
69244 <- BasicObject::singleton_method_added <internal:dir>:42
69244 -> BasicObject::singleton_method_added <internal:dir>:133
69244 <- BasicObject::singleton_method_added <internal:dir>:133
69244 -> BasicObject::singleton_method_added <internal:ast>:34
69244 <- BasicObject::singleton_method_added <internal:ast>:34
69244 -> BasicObject::singleton_method_added <internal:ast>:49
69244 <- BasicObject::singleton_method_added <internal:ast>:49
69244 -> BasicObject::singleton_method_added <internal:ast>:68
69244 <- BasicObject::singleton_method_added <internal:ast>:68
69244 -> Module::method_added <internal:ast>:90
69244 <- Module::method_added <internal:ast>:90
69244 -> Module::method_added <internal:ast>:98
69244 <- Module::method_added <internal:ast>:98
69244 -> Module::method_added <internal:ast>:106
69244 <- Module::method_added <internal:ast>:106
69244 -> Module::method_added <internal:ast>:114
69244 <- Module::method_added <internal:ast>:114
69244 -> Module::method_added <internal:ast>:122
69244 <- Module::method_added <internal:ast>:122
69244 -> Module::method_added <internal:ast>:133
69244 <- Module::method_added <internal:ast>:133
69244 -> Module::method_added <internal:ast>:141
69244 <- Module::method_added <internal:ast>:141
69244 -> BasicObject::singleton_method_added <internal:trace_point>:95
69244 <- BasicObject::singleton_method_added <internal:trace_point>:95
69244 -> Module::method_added <internal:trace_point>:104
69244 <- Module::method_added <internal:trace_point>:104
69244 -> BasicObject::singleton_method_added <internal:trace_point>:117
69244 <- BasicObject::singleton_method_added <internal:trace_point>:117
69244 -> BasicObject::singleton_method_added <internal:trace_point>:134
69244 <- BasicObject::singleton_method_added <internal:trace_point>:134
69244 -> Module::method_added <internal:trace_point>:195
69244 <- Module::method_added <internal:trace_point>:195
69244 -> Module::method_added <internal:trace_point>:231
69244 <- Module::method_added <internal:trace_point>:231
69244 -> Module::method_added <internal:trace_point>:239
69244 <- Module::method_added <internal:trace_point>:239
69244 -> Module::method_added <internal:trace_point>:246
69244 <- Module::method_added <internal:trace_point>:246
69244 -> Module::method_added <internal:trace_point>:251
69244 <- Module::method_added <internal:trace_point>:251
69244 -> Module::method_added <internal:trace_point>:256
69244 <- Module::method_added <internal:trace_point>:256
69244 -> Module::method_added <internal:trace_point>:262
69244 <- Module::method_added <internal:trace_point>:262
69244 -> Module::method_added <internal:trace_point>:267
69244 <- Module::method_added <internal:trace_point>:267
69244 -> Module::method_added <internal:trace_point>:272
69244 <- Module::method_added <internal:trace_point>:272
69244 -> Module::method_added <internal:trace_point>:308
69244 <- Module::method_added <internal:trace_point>:308
69244 -> Module::method_added <internal:trace_point>:313
69244 <- Module::method_added <internal:trace_point>:313
69244 -> Module::method_added <internal:trace_point>:321
69244 <- Module::method_added <internal:trace_point>:321
69244 -> Module::method_added <internal:trace_point>:326
69244 <- Module::method_added <internal:trace_point>:326
69244 -> Module::method_added <internal:trace_point>:331
69244 <- Module::method_added <internal:trace_point>:331
69244 -> Module::method_added <internal:trace_point>:337
69244 <- Module::method_added <internal:trace_point>:337
69244 -> Module::method_added <internal:trace_point>:345
69244 <- Module::method_added <internal:trace_point>:345
69244 -> Module::method_added <internal:pack>:133
69244 <- Module::method_added <internal:pack>:133
69244 -> Module::method_added <internal:pack>:256
69244 <- Module::method_added <internal:pack>:256
69244 -> Module::method_added <internal:pack>:280
69244 <- Module::method_added <internal:pack>:280
69244 -> Module::module_function <internal:warning>:5
69244 <- Module::module_function <internal:warning>:5
69244 -> Module::method_added <internal:warning>:50
69244 <- Module::method_added <internal:warning>:50
69244 -> BasicObject::singleton_method_added <internal:warning>:50
69244 <- BasicObject::singleton_method_added <internal:warning>:50
69244 -> Module::method_added <internal:array>:12
69244 <- Module::method_added <internal:array>:12
69244 -> Module::method_added <internal:array>:26
69244 <- Module::method_added <internal:array>:26
69244 -> Module::method_added <internal:array>:58
69244 <- Module::method_added <internal:array>:58
69244 -> Module::method_added <internal:kernel>:18
69244 <- Module::method_added <internal:kernel>:18
69244 -> Module::method_added <internal:kernel>:47
69244 <- Module::method_added <internal:kernel>:47
69244 -> Module::method_added <internal:kernel>:67
69244 <- Module::method_added <internal:kernel>:67
69244 -> Module::method_added <internal:kernel>:89
69244 <- Module::method_added <internal:kernel>:89
69244 -> Module::method_added <internal:kernel>:120
69244 <- Module::method_added <internal:kernel>:120
69244 -> Module::method_added <internal:kernel>:144
69244 <- Module::method_added <internal:kernel>:144
69244 -> Module::module_function <internal:kernel>:151
69244 <- Module::module_function <internal:kernel>:151
69244 -> Module::method_added <internal:kernel>:171
69244 <- Module::method_added <internal:kernel>:171
69244 -> BasicObject::singleton_method_added <internal:kernel>:171
69244 <- BasicObject::singleton_method_added <internal:kernel>:171
69244 -> Module::method_added <internal:prelude>:3
69244 <- Module::method_added <internal:prelude>:3
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:prelude>:9
69244 -> Module::method_added <internal:prelude>:9
69244 <- Module::method_added <internal:prelude>:9
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:prelude>:9
69244 -> Module::method_added <internal:prelude>:13
69244 <- Module::method_added <internal:prelude>:13
69244 -> RubyVM::FrozenCore::core#set_method_alias <internal:prelude>:19
69244 -> Module::method_added <internal:prelude>:19
69244 <- Module::method_added <internal:prelude>:19
69244 <- RubyVM::FrozenCore::core#set_method_alias <internal:prelude>:19
69244 -> Module::private <internal:prelude>:21
69244 <- Module::private <internal:prelude>:21
69244 -> Kernel::require <internal:gem_prelude>:2
69244 -> IO::set_encoding <internal:gem_prelude>:2
69244 <- IO::set_encoding <internal:gem_prelude>:2
69244 -> IO::set_encoding <internal:gem_prelude>:2
69244 <- IO::set_encoding <internal:gem_prelude>:2
69244 gc.mark.begin
69244 gc.sweep.begin
69244 gc.sweep.end
69244 gc.mark.end
69244 -> Kernel::require /usr/share/rubygems/rubygems.rb:8
69244 -> IO::set_encoding /usr/share/rubygems/rubygems.rb:8
69244 <- IO::set_encoding /usr/share/rubygems/rubygems.rb:8
69244 -> IO::set_encoding /usr/share/rubygems/rubygems.rb:8
69244 <- IO::set_encoding /usr/share/rubygems/rubygems.rb:8
69244 -> String::start_with? /usr/lib64/ruby/rbconfig.rb:12
69244 <- String::start_with? /usr/lib64/ruby/rbconfig.rb:12
69244 -> File::dirname /usr/lib64/ruby/rbconfig.rb:16
69244 <- File::dirname /usr/lib64/ruby/rbconfig.rb:16
69244 -> String::chomp! /usr/lib64/ruby/rbconfig.rb:16
69244 <- String::chomp! /usr/lib64/ruby/rbconfig.rb:16
69244 gc.sweep.begin

And somebody might wonder what is the state of the object which should supposedly hold the classname:

(gdb) call ruby_debug_print_v(rb_mRubyVMFrozenCore)
DBG> : 0x00000001000a09c8 [3LM R ] T_ICLASS 
(gdb) p *(*(struct RClass *)(rb_mRubyVMFrozenCore))->ptr.iv_tbl.entries
$4 = {hash = 30421, key = 3809, record = 4295625080}
(gdb)  p *(struct RBasic *)(4295625080)
$5 = {flags = 0, klass = 4295624320}
(gdb) call ruby_debug_print_v(4295625080)
DBG> : 0x00000001000a0978 [0     ] T_NONE 

So while the rb_mRubyVMFrozenCore is still the same, the description object changed to T_NONE. Running even further, the content changes again in rb_dtrace_setup call:

(gdb) c
Continuing.

Watchpoint 2: ((struct RBasic *)(4295625080))->klass

Old value = 4295624320
New value = 4295927560
0x00007ffff7bed4b4 in rb_wb_protected_newobj_of (klass=4295927560, flags=5) at gc.c:2356
2356	}
(gdb) bt
#0  0x00007ffff7bed4b4 in rb_wb_protected_newobj_of (klass=4295927560, flags=5) at gc.c:2356
#1  0x00007ffff7d4b86c in str_alloc (klass=<optimized out>) at string.c:773
#2  str_duplicate (str=4295960160, klass=<optimized out>) at string.c:1601
#3  rb_str_dup (str=4295960160) at string.c:1608
#4  0x00007ffff7da72ac in rb_class_path (klass=4295960120) at variable.c:173
#5  0x00007ffff7dc46a4 in rb_dtrace_setup (ec=<optimized out>, klass=4295960120, id=3137, args=0x7fffffffa198) at vm.c:449
#6  0x00007ffff7dd83c4 in vm_call0_cfunc_with_frame (argv=0x7fffffffa330, calling=0x7fffffffa1b8, ec=0x100031cf0) at vm_eval.c:124
#7  vm_call0_cfunc (argv=0x7fffffffa330, calling=0x7fffffffa1b8, ec=0x100031cf0) at vm_eval.c:149
#8  vm_call0_body (ec=ec@entry=0x100031cf0, calling=calling@entry=0x7fffffffa278, argv=argv@entry=0x7fffffffa330) at vm_eval.c:180
#9  0x00007ffff7ddb9a0 in vm_call0_cc (kw_splat=0, cc=0x100211230, argv=0x7fffffffa330, argc=1, id=3137, recv=4295625120, ec=0x100031cf0) at vm_eval.c:72
#10 rb_funcallv_scope (scope=CALL_FCALL, argv=0x7fffffffa330, argc=1, mid=3137, recv=4295625120) at vm_eval.c:1006
#11 rb_funcallv (recv=4295625120, mid=3137, argc=<optimized out>, argv=0x7fffffffa330) at vm_eval.c:1026
#12 0x00007ffff7c88f60 in rb_obj_dup (obj=<error reading variable: value has been optimized out>) at object.c:568
#13 rb_obj_dup (obj=<error reading variable: value has been optimized out>) at object.c:559
#14 0x00007ffff7daf4e4 in ractor_safe_call_cfunc_0 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2743
#15 0x00007ffff7dc4900 in vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75afe18, calling=<optimized out>) at vm_insnhelper.c:2926
#16 0x00007ffff7dc7644 in vm_sendish (ec=0x100031cf0, reg_cfp=0x7ffff75afe18, cd=0x100218e70, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#17 0x00007ffff7dcba5c in vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#18 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#19 0x00007ffff7dd5b4c in invoke_block (captured=<optimized out>, captured=<optimized out>, opt_pc=<optimized out>, type=<optimized out>, cref=0x0, self=<optimized out>, iseq=<optimized out>, ec=0x100031cf0)
    at vm.c:1263
#20 invoke_iseq_block_from_c (me=0x0, is_lambda=<optimized out>, cref=0x0, passed_block_handler=0, kw_splat=0, argv=<optimized out>, argc=2, self=<optimized out>, captured=<optimized out>, ec=0x100031cf0)
    at vm.c:1335
#21 invoke_block_from_c_bh (ec=0x100031cf0, block_handler=<optimized out>, argc=<optimized out>, argv=<optimized out>, kw_splat=<optimized out>, passed_block_handler=0, cref=0x0, is_lambda=<optimized out>, 
    force_blockarg=0) at vm.c:1353
#22 0x00007ffff7dd6db4 in vm_yield (kw_splat=0, argv=0x7fffffffac68, argc=2, ec=<optimized out>) at vm.c:1398
#23 rb_yield_0 (argv=0x7fffffffac68, argc=2) at vm_eval.c:1331
#24 rb_yield_values2 (argc=<optimized out>, argv=0x7fffffffac68) at vm_eval.c:1377
#25 0x00007ffff7bf0300 in each_pair_i_fast (key=<optimized out>, value=<optimized out>, _=<optimized out>) at hash.c:3116
#26 0x00007ffff7beffe4 in hash_foreach_iter (key=<optimized out>, value=<optimized out>, argp=140737488335344, error=<optimized out>) at hash.c:1378
#27 0x00007ffff7d37378 in st_general_foreach (tab=0x100202120, func=0x7ffff7beffa0 <hash_foreach_iter>, replace=0x0, arg=140737488335344, check_p=<optimized out>) at st.c:1473
#28 0x00007ffff7bf3ba0 in hash_foreach_call (arg=140737488335344) at hash.c:1507
#29 0x00007ffff7bc2fa0 in rb_ensure (b_proc=0x7ffff7bf3a60 <hash_foreach_call>, data1=140737488335344, e_proc=0x7ffff7bf1f80 <hash_foreach_ensure>, data2=<optimized out>) at eval.c:1162
#30 0x00007ffff7bf63c0 in rb_hash_foreach (farg=0, func=0x7ffff7bf02c0 <each_pair_i_fast>, hash=4295229560) at hash.c:1527
#31 rb_hash_foreach (hash=4295229560, func=0x7ffff7bf02c0 <each_pair_i_fast>, farg=0) at hash.c:1517
#32 0x00007ffff7bf7480 in rb_hash_each_pair (hash=4295229560) at hash.c:3153
#33 0x00007ffff7daf4e4 in ractor_safe_call_cfunc_0 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2743
#34 0x00007ffff7dc4900 in vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75afe88, calling=<optimized out>) at vm_insnhelper.c:2926
#35 0x00007ffff7dc7644 in vm_sendish (ec=0x100031cf0, reg_cfp=0x7ffff75afe88, cd=0x10022b6e0, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#36 0x00007ffff7dcbac8 in vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:770
#37 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#38 0x00007ffff7dd29f4 in rb_iseq_eval (iseq=0x10004a410) at vm.c:2409
#39 0x00007ffff7c2ce68 in load_iseq_eval (fname=4295431320, ec=0x100031cf0) at load.c:594
#40 require_internal (ec=ec@entry=0x100031cf0, fname=<optimized out>, fname@entry=4295211000, exception=exception@entry=1) at load.c:1065
#41 0x00007ffff7c2e7f4 in rb_require_string (fname=4295211000) at load.c:1142
#42 0x00007ffff7c2e88c in rb_f_require (obj=<optimized out>, fname=<optimized out>) at load.c:838
#43 0x00007ffff7daf538 in ractor_safe_call_cfunc_1 (recv=<optimized out>, argc=<optimized out>, argv=<optimized out>, func=<optimized out>) at vm_insnhelper.c:2750
#44 0x00007ffff7dc4900 in vm_call_cfunc_with_frame (ec=0x100031cf0, reg_cfp=0x7ffff75aff30, calling=<optimized out>) at vm_insnhelper.c:2926
#45 0x00007ffff7dc7644 in vm_sendish (ec=0x100031cf0, reg_cfp=0x7ffff75aff30, cd=0x100121e10, block_handler=<optimized out>, method_explorer=<optimized out>) at vm_callinfo.h:336
#46 0x00007ffff7dcba5c in vm_exec_core (ec=0x100031cf0, initial=<optimized out>, initial@entry=0) at insns.def:789
#47 0x00007ffff7dd1710 in rb_vm_exec (ec=0x100031cf0, mjit_enable_p=<optimized out>) at vm.c:2172
#48 0x00007ffff7dd29f4 in rb_iseq_eval (iseq=0x10003b988) at vm.c:2409
#49 0x00007ffff7c2ce68 in load_iseq_eval (fname=4295394400, ec=0x100031cf0) at load.c:594
#50 require_internal (ec=ec@entry=0x100031cf0, fname=<optimized out>, fname@entry=4295394680, exception=exception@entry=1) at load.c:1065
--Type <RET> for more, q to quit, c to continue without paging--q
Quit
(gdb) p *(*(struct RClass *)(rb_mRubyVMFrozenCore))->ptr.iv_tbl.entries
$10 = {hash = 30421, key = 3809, record = 4295625080}
(gdb) p *(struct RBasic *)(4295625080)
$11 = {flags = 0, klass = 4295927560}

I am not really sure what happens after this point ...

However, my assumption is that RubyVM::FrozenCore::core#set_method_alias in its form won't apper in the log anymore and there will be some rubbish instead.

[1] https://github.com/ruby/ruby/blob/v3_0_2/vm.c#L3388

[vo.x (Vit Ondruch)]

• Subject changed from SystemTap/DTrace coredump to rb_mRubyVMFrozenCore is broken by GC run

To demonstrate the issue without SystemTap using Ruby 3.1.0, I have created the following patch:

$ git diff
diff --git a/gc.c b/gc.c
index d77dc2cda4..6a00742209 100644
--- a/gc.c
+++ b/gc.c
@@ -5627,6 +5627,9 @@ gc_sweep_finish(rb_objspace_t *objspace)
 static int
 gc_sweep_step(rb_objspace_t *objspace, rb_size_pool_t *size_pool, rb_heap_t *heap)
 {
+    VALUE path = rb_class_path_cached(rb_mRubyVMFrozenCore);
+    printf("Before sweep: %s\n", RSTRING_PTR(path));
+
     struct heap_page *sweep_page = heap->sweeping_page;
     int unlink_limit = 3;
 
@@ -5714,6 +5717,9 @@ gc_sweep_step(rb_objspace_t *objspace, rb_size_pool_t *size_pool, rb_heap_t *hea
     gc_prof_sweep_timer_stop(objspace);
 #endif
 
+    path = rb_class_path_cached(rb_mRubyVMFrozenCore);
+    printf("After sweep: %s\n", RSTRING_PTR(path));
+
     return heap->free_pages != NULL;
 }
 
@@ -8138,6 +8144,9 @@ gc_marks_continue(rb_objspace_t *objspace, rb_size_pool_t *size_pool, rb_heap_t
 static void
 gc_marks(rb_objspace_t *objspace, int full_mark)
 {
+    VALUE path = rb_class_path_cached(rb_mRubyVMFrozenCore);
+    printf("Before mark: %s\n", RSTRING_PTR(path));
+
     gc_prof_mark_timer_start(objspace);
 
     /* setup marking */
@@ -8154,6 +8163,9 @@ gc_marks(rb_objspace_t *objspace, int full_mark)
     }
 #endif
     gc_prof_mark_timer_stop(objspace);
+
+    path = rb_class_path_cached(rb_mRubyVMFrozenCore);
+    printf("After mark: %s\n", RSTRING_PTR(path));
 }
 
 /* RGENGC */

With simple test case, it produces this output:

$ ./miniruby -e "10000.times {[1].push[2]}"
Before mark: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
After mark: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before mark: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before sweep: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.After sweep: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.After mark: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before sweep: (null)
After sweep: 
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before mark: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before sweep: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.After sweep: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.After mark: (null)
RSTRING_PTR is returning NULL!! SIGSEGV is highly expected to follow immediately. If you could reproduce, attach your debugger here, and look at the passed string.Before sweep: (null)
After sweep: 

With more complex examples which are part of Ruby build:

$ ./miniruby -I./lib -I. -I.ext/common  ./tool/generic_erb.rb -c -o encdb.h ./template/encdb.h.tmpl ./enc enc
Before mark: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
After mark: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before mark:     module_function :def_erb_method

Before sweep:     module_function :def_erb_method

After sweep:     module_function :def_erb_method

After mark:     module_function :def_erb_method

Before sweep:     module_function :def_erb_method

After sweep: $
Before mark: end

Before sweep: end

After sweep: end

After mark: end

/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:474: [BUG] Segmentation fault at 0x0000000000009619
ruby 3.1.0p0 (2021-12-25 revision fb4df44d16) [x86_64-linux]

-- Control frame information -----------------------------------------------
c:0014 p:---- s:0088 e:000087 CFUNC  :scan
c:0013 p:0008 s:0083 e:000082 METHOD /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:474 [FINISH]
c:0012 p:---- s:0078 e:000077 CFUNC  :call
c:0011 p:0028 s:0073 e:000072 METHOD /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:417
c:0010 p:0009 s:0067 e:000066 BLOCK  /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:407 [FINISH]
c:0009 p:---- s:0063 e:000062 CFUNC  :each_line
c:0008 p:0015 s:0059 e:000058 METHOD /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:406
c:0007 p:0088 s:0054 E:0001a8 METHOD /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:593
c:0006 p:0140 s:0045 e:000044 METHOD /builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:827 [FINISH]
c:0005 p:---- s:0033 e:000032 CFUNC  :new
c:0004 p:0048 s:0027 e:000026 BLOCK  ./tool/generic_erb.rb:36 [FINISH]
c:0003 p:---- s:0022 e:000021 CFUNC  :map
c:0002 p:0106 s:0018 E:000f00 EVAL   ./tool/generic_erb.rb:34 [FINISH]
c:0001 p:0000 s:0003 E:0018d0 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
./tool/generic_erb.rb:34:in `<main>'
./tool/generic_erb.rb:34:in `map'
./tool/generic_erb.rb:36:in `block in <main>'
./tool/generic_erb.rb:36:in `new'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:827:in `initialize'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:593:in `compile'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:406:in `scan'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:406:in `each_line'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:407:in `block in scan'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:417:in `percent_line'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:417:in `call'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:474:in `explicit_trim_line'
/builddir/build/BUILD/ruby-3.1.0/lib/erb.rb:474:in `scan'

-- Machine register context ------------------------------------------------
 RIP: 0x00007f8be6ecd4bd RBP: 0x00007f8be6f465a0 RSP: 0x00007ffd889a0fb8
 RAX: 0x0000000000000619 RBX: 0x0000000000000073 RCX: 0x00007f8be6f02460
 RDX: 0x0000000000009619 RDI: 0x0000000000009619 RSI: 0x00007f8be6f024e0
  R8: 0x00007f8be6f023e0  R9: 0x0000000000000000 R10: 0x0000000000000000
 R11: 0x0000000000000000 R12: 0x000000000000000e R13: 0x00000000ffffffff
 R14: 0x0000000000009619 R15: 0x00007ffd889a1510 EFL: 0x0000000000010287

-- C level backtrace information -------------------------------------------
./miniruby(rb_print_backtrace+0x19) [0x564965148c49]
./miniruby(rb_vm_bugreport+0x219) [0x56496514c7f9]
./miniruby(rb_bug_for_fatal_signal+0xf4) [0x564964f75204]
./miniruby(sigsegv+0x4f) [0x5649650bad7f]
[0x7f8be6d94700]
[0x7f8be6ecd4bd]
[0x7f8be6dc44b1]
[0x7f8be6e71b4b]
./miniruby(gc_sweep_step.isra.0+0x7b) [0x56496518797b]
./miniruby(heap_prepare.lto_priv.0+0x54) [0x564964f99754]
./miniruby(newobj_slowpath_wb_protected.constprop.0+0x136) [0x5649651715c6]
./miniruby(rb_wb_protected_newobj_of+0x8e) [0x564964f901de]
./miniruby(str_new0.lto_priv.0+0x6b) [0x5649650c4cbb]
./miniruby(rb_str_subseq+0x9f) [0x5649650cd8af]
./miniruby(scan_once+0x11b) [0x5649650ddeab]
./miniruby(rb_str_scan.lto_priv.0+0x108) [0x5649650de128]
./miniruby(vm_call_cfunc_with_frame+0x125) [0x564965125555]
./miniruby(vm_sendish.lto_priv.0+0x4ba) [0x564965126dea]
./miniruby(vm_exec_core.lto_priv.0+0x6bf) [0x56496512f9ff]
./miniruby(rb_vm_exec+0xc9) [0x564965146169]
./miniruby(rb_vm_call0+0xe4) [0x564965139e04]
./miniruby(rb_method_call_with_block_kw+0x7f) [0x56496505ba5f]
./miniruby(vm_call_cfunc_with_frame+0x125) [0x564965125555]
./miniruby(vm_sendish.lto_priv.0+0x4ba) [0x564965126dea]
./miniruby(vm_exec_core.lto_priv.0+0x6bf) [0x56496512f9ff]
./miniruby(rb_vm_exec+0xc9) [0x564965146169]
./miniruby(rb_yield+0x78) [0x564965136288]
./miniruby(rb_str_enumerate_lines+0x588) [0x5649650e0bb8]
./miniruby(vm_call_cfunc_with_frame+0x125) [0x564965125555]
./miniruby(vm_sendish.lto_priv.0+0x4ba) [0x564965126dea]
./miniruby(vm_exec_core.lto_priv.0+0x6bf) [0x56496512f9ff]
./miniruby(rb_vm_exec+0xc9) [0x564965146169]
./miniruby(rb_call0.lto_priv.0+0x1e1) [0x5649651387d1]
./miniruby(rb_obj_call_init_kw+0x85) [0x564964f7d5b5]
./miniruby(rb_class_new_instance_pass_kw+0x58) [0x56496502dfb8]
./miniruby(vm_call_cfunc_with_frame+0x125) [0x564965125555]
./miniruby(vm_sendish.lto_priv.0+0x4ba) [0x564965126dea]
./miniruby(vm_exec_core.lto_priv.0+0x82) [0x56496512f3c2]
./miniruby(rb_vm_exec+0xc9) [0x564965146169]
./miniruby(rb_yield+0x78) [0x564965136288]
./miniruby(rb_ary_collect.lto_priv.0+0x12c) [0x564964ef954c]
./miniruby(vm_call_cfunc_with_frame+0x125) [0x564965125555]
./miniruby(vm_sendish.lto_priv.0+0x4ba) [0x564965126dea]
./miniruby(vm_exec_core.lto_priv.0+0x6bf) [0x56496512f9ff]
./miniruby(rb_vm_exec+0xc9) [0x564965146169]
./miniruby(rb_ec_exec_node+0xa7) [0x564964f7e927]
./miniruby(ruby_run_node+0x69) [0x564964f83d79]
./miniruby(main+0x5f) [0x564964ef201f]

For my original case triggered by DTrace probe, I'll probably avoid reporting anything for rb_mRubyVMFrozenCore or I special case the class name there.

[vo.x (Vit Ondruch)]

Going to apply the following workaround until this is fixed:

From 0ade5611df9f981005eed32b369d1e699e520221 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?V=C3=ADt=20Ondruch?= <[e-mail]>
Date: Thu, 10 Feb 2022 13:26:44 +0100
Subject: [PATCH] Don't query `RubyVM::FrozenCore` for class path.

The `RubyVM::FrozenCore` class path is corrupted during GC cycle and
returns random garbage, which might result in segfault.

But since it is easy to detect the `RubyVM::FrozenCore`, just provide
the class path explicitly as a workaround.

Other possibility would be to ignore `RubyVM::FrozenCore` simlarly as
TracePoint API does:

https://github.com/ruby/ruby/blob/46f6575157d4c2f6bbd5693896e26a65037e5552/vm_trace.c#L411
---
 vm.c | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/vm.c b/vm.c
index 8ce8b279d4..3d189fa63a 100644
--- a/vm.c
+++ b/vm.c
@@ -479,7 +479,15 @@ rb_dtrace_setup(rb_execution_context_t *ec, VALUE klass, ID id,
     }
     type = BUILTIN_TYPE(klass);
     if (type == T_CLASS || type == T_ICLASS || type == T_MODULE) {
-	VALUE name = rb_class_path(klass);
+	VALUE name = Qnil;
+	/*
+	 * Special treatment for rb_mRubyVMFrozenCore wchi is broken by GC.
+         * https://bugs.ruby-lang.org/issues/18257
+	 */
+	if (klass == rb_mRubyVMFrozenCore)
+	    name = rb_str_new_cstr("RubyVM::FrozenCore");
+	else
+	    name = rb_class_path(klass);
 	const char *classname, *filename;
 	const char *methodname = rb_id2name(id);
 	if (methodname && (filename = rb_source_location_cstr(&args->line_no)) != 0) {
-- 
2.34.1

[jeremyevans0 (Jeremy Evans)]

• Status changed from Open to Feedback

@vo.x (Vit Ondruch) This may have been fixed by 813a5f4fc46a24ca1695d23c159250b9e1080ac7, can you see if this is still a problem?

[vo.x (Vit Ondruch)]

I don't think this is resolved, at least to the full extent. Trying again with the patch from comment #18257-13 and this is the results:

$ ./miniruby -v
ruby 3.3.0dev (2023-09-05 master 7c8932365f) [x86_64-linux]

$ ./miniruby -e "10000.times {[1].push[2]}"
Before mark: RubyVM::FrozenCore
After mark: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
After sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
Before sweep: RubyVM::FrozenCore
Before mark: RubyVM::FrozenCore
After mark: RubyVM::FrozenCore
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before mark: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After mark: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before mark: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After mark: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
Before sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)
After sweep: OFFSETOF((*((struct rb_iseq_struct *)NULL)), aux)

Either the patch is completely off or something strange happens somewhere with the rb_mRubyVMFrozenCore

[vo.x (Vit Ondruch)]

Trying to reproduce all the steps, I still observe the behavior as described in comment #18257-12. I'll keep around the patch as described in #18257-14 until this is fixed properly.

[nobu (Nobuyoshi Nakada)]

• Status changed from Feedback to Open

[nobu (Nobuyoshi Nakada)]

• Status changed from Open to Closed

Applied in changeset git|647390308239fbf82d159ecd83ed8df090af518d.

---

[Bug #18257] Register the class path of FrozenCore to mark

ICLASS does not have the path usually, so it needs to be registered
separately.

[nobu (Nobuyoshi Nakada)]

• Backport changed from 2.6: UNKNOWN, 2.7: UNKNOWN, 3.0: UNKNOWN to 3.0: REQUIRED, 3.1: REQUIRED, 3.2: REQUIRED

[vo.x (Vit Ondruch)]

Thx a lot!

[vo.x (Vit Ondruch)]

BTW I still wonder what is the reason for 1:

        if (ec->trace_arg == NULL && /* check reentrant */
            trace_arg->self != rb_mRubyVMFrozenCore /* skip special methods. TODO: remove it. */) {

This was introduced in git|1be7c799e6ed39f7ac41906c05db149e8c391add but hard to guess what was the reason. If there were issues or if it is by design.

[vo.x (Vit Ondruch)]

The TODO part was introduced by git|4a4a702e61d1c5585d522f1185a82a5685c554f6 which also does not give a clue what is intention here.

Generally, my point is that it is strange that DTrace would report about rb_mRubyVMFrozenCore while TracePoint is happy to skip it.