- ruby-core - ml.ruby-lang.org

[ruby-core:113381] [Ruby master Bug#19624] Backticks - IO object leakage
by pineman 20 Sep '23

20 Sep '23

Issue #19624 has been reported by pineman (João Pinheiro). ---------------------------------------- Bug #19624: Backticks - IO object leakage https://bugs.ruby-lang.org/issues/19624 * Author: pineman (João Pinheiro) * Status: Open * Priority: Normal * ruby -v: ruby 3.2.2 (2023-03-30 revision e51014f9c0) [arm64-darwin22] * Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN ---------------------------------------- Hi, This code works on ruby 3.0.6: ```ruby `echo` ObjectSpace.each_object(IO) do |io| if ![STDIN, STDOUT, STDERR].include?(io) io.close end end ``` but raises `IOError` on 3.2.2: ``` minimal-repro-case.rb:8:in `close': uninitialized stream (IOError) ``` I found it started failing on ruby 3.1.0 and after, on macOS and Linux. This code is useful for closing unneeded IO objects in forked processes. It looks like backticks is 'leaking' IO objects, waiting for GC, and it didn't used to in 3.1.0. In ruby 3.1.0, inside `rb_f_backquote`, `rb_gc_force_recycle` was removed in favor of `RB_GC_GUARD`. I wonder if this has something to do with the problem. Is this code incorrect since ruby 3.1.0 or is it a bug in ruby? Thanks. ---Files-------------------------------- minimal-repro-case.rb (109 Bytes) -- https://bugs.ruby-lang.org/

4 9

[ruby-core:114824] [Ruby master Bug#4040] SystemStackError with Hash[*a] for Large _a_
by tenderlovemaking (Aaron Patterson) 20 Sep '23

20 Sep '23

Issue #4040 has been updated by tenderlovemaking (Aaron Patterson). Hi, We (on the YJIT team) have been tracking Ruby performance. We usually look at YJIT performance as compared to the interpreter, but recently we started looking at interpreter performance (it's getting later in the year so we want to make sure things look good for the release). We noticed there was a degradation in interpreter performance in April, and I tracked the issue to this commit. We were specifically looking at [the chunky png benchmark](https://github.com/Shopify/yjit-bench/blob/main/benchmarks/chunk…. If you check [this graph](https://rubybench.github.io/benchmarks/yjit-bench.html#chunky_png) then click "Time" on the bottom, you can see the increase in time in April. Running `perf stat` on the benchmark shows this commit increases the executed instructions from 232,171,088,239 to 244,008,191,171. Here is the `perf stat` results I got for e7cdce83e8: ``` Performance counter stats for 'ruby -v benchmark.rb': 18,995.65 msec task-clock # 1.000 CPUs utilized 68 context-switches # 3.580 /sec 1 cpu-migrations # 0.053 /sec 33,003 page-faults # 1.737 K/sec 82,022,881,262 cycles # 4.318 GHz (83.32%) 449,576,108 stalled-cycles-frontend # 0.55% frontend cycles idle (83.32%) 21,629,264,292 stalled-cycles-backend # 26.37% backend cycles idle (83.33%) 232,171,088,239 instructions # 2.83 insn per cycle # 0.09 stalled cycles per insn (83.35%) 40,092,228,662 branches # 2.111 G/sec (83.37%) 76,492,242 branch-misses # 0.19% of all branches (83.34%) 18.997823376 seconds time elapsed 18.904486000 seconds user 0.091909000 seconds sys ``` vs `perf stat` for 99c6d19e50 ``` Performance counter stats for 'ruby -v benchmark.rb': 19,415.14 msec task-clock # 1.000 CPUs utilized 66 context-switches # 3.399 /sec 2 cpu-migrations # 0.103 /sec 38,513 page-faults # 1.984 K/sec 82,876,137,933 cycles # 4.269 GHz (83.32%) 577,427,117 stalled-cycles-frontend # 0.70% frontend cycles idle (83.33%) 20,414,833,187 stalled-cycles-backend # 24.63% backend cycles idle (83.35%) 244,008,191,171 instructions # 2.94 insn per cycle # 0.08 stalled cycles per insn (83.37%) 41,385,015,387 branches # 2.132 G/sec (83.35%) 76,702,379 branch-misses # 0.19% of all branches (83.32%) 19.417447024 seconds time elapsed 19.346844000 seconds user 0.068922000 seconds sys ``` It's cool we could fix a 13 year old bug, but given the "rarity" of this issue I'm not sure it's worth the slowdown? 😅 I will try to find some way to speed this up, but I'm not sure if I'll have time. In case someone has time to look, the way to reproduce this is by checking out [yjit-bench](https://github.com/shopify/yjit-bench) then running [the chunky-png benchmark](https://github.com/Shopify/yjit-bench/blob/main/benchmarks/chunk… like this: `perf stat ruby -v benchmark.rb` ---------------------------------------- Bug #4040: SystemStackError with Hash[*a] for Large _a_ https://bugs.ruby-lang.org/issues/4040#change-104668 * Author: runpaint (Run Paint Run Run) * Status: Closed * Priority: Normal * Assignee: ko1 (Koichi Sasada) * ruby -v: ruby 1.9.3dev (2010-11-09 trunk 29737) [x86_64-linux] * Backport: 2.2: UNKNOWN, 2.3: UNKNOWN, 2.4: UNKNOWN ---------------------------------------- =begin I've been hesitating over whether to file a ticket about this, so please feel free to close if I've made the wrong choice. I often use Hash[*array.flatten] in IRB to convert arrays of arrays into hashes. Today I noticed that if the array is big enough, this would raise a SystemStackError. Puzzled, I looked deeper. I assumed I was hitting the maximum number of arguments a method's argc can hold, but realised that the minimum size of the array needed to trigger this exception differed depending on whether I used IRB or not. So, presumably this is indeed exhausting the stack... In IRB, the following is the minimal reproduction of this problem: Hash[*130648.times.map{ 1 }]; true I haven't looked for the minimum value needed with `ruby -e`, but the following reproduces: ruby -e 'Hash[*1380888.times.map{ 1 }]' I suppose this isn't technically a bug, but maybe it offers another argument for either #666 or an extension of #3131. =end -- https://bugs.ruby-lang.org/

1 0

[ruby-core:114814] [Ruby master Bug#19891] rb_mRubyVMFrozenCore is reported by DTrace but ignored by TracePoint
by vo.x (Vit Ondruch) 19 Sep '23

19 Sep '23

Issue #19891 has been reported by vo.x (Vit Ondruch). ---------------------------------------- Bug #19891: rb_mRubyVMFrozenCore is reported by DTrace but ignored by TracePoint https://bugs.ruby-lang.org/issues/19891 * Author: vo.x (Vit Ondruch) * Status: Open * Priority: Normal * ruby -v: ruby 3.3.0dev (2023-09-05 master 7c8932365f) [x86_64-linux] * Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN ---------------------------------------- This is related to #18257 where I wonder why rb_mRubyVMFrozenCore is ignored by TracePoint (if I am not mistaken) [1]: ~~~ if (ec->trace_arg == NULL && /* check reentrant */ trace_arg->self != rb_mRubyVMFrozenCore /* skip special methods. TODO: remove it. */) { ~~~ This was introduced in commit:git|1be7c799e6ed39f7ac41906c05db149e8c391add but hard to guess what was the reason. If there were issues similar to @18257 or if it is by design. The `TODO` part was introduced by commit: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. [1]: https://github.com/ruby/ruby/blob/647390308239fbf82d159ecd83ed8df090af518d/… -- https://bugs.ruby-lang.org/

2 1

[ruby-core:114813] [Ruby master Bug#18257] rb_mRubyVMFrozenCore is broken by GC run
by vo.x (Vit Ondruch) 19 Sep '23

19 Sep '23

Issue #18257 has been updated by vo.x (Vit Ondruch). The `TODO` part was introduced by commit: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. ---------------------------------------- Bug #18257: rb_mRubyVMFrozenCore is broken by GC run https://bugs.ruby-lang.org/issues/18257#change-104660 * Author: vo.x (Vit Ondruch) * Status: Closed * Priority: Normal * ruby -v: ruby 3.0.3p157 (2021-11-24 revision 3fb7d2cadc) [x86_64-linux] * Backport: 3.0: REQUIRED, 3.1: REQUIRED, 3.2: REQUIRED ---------------------------------------- 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 ~~~ -- https://bugs.ruby-lang.org/

1 0

[ruby-core:114812] [Ruby master Bug#18257] rb_mRubyVMFrozenCore is broken by GC run
by vo.x (Vit Ondruch) 19 Sep '23

19 Sep '23

Issue #18257 has been updated by 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 commit:git|1be7c799e6ed39f7ac41906c05db149e8c391add but hard to guess what was the reason. If there were issues or if it is by design. [1]: https://github.com/ruby/ruby/blob/647390308239fbf82d159ecd83ed8df090af518d/… ---------------------------------------- Bug #18257: rb_mRubyVMFrozenCore is broken by GC run https://bugs.ruby-lang.org/issues/18257#change-104659 * Author: vo.x (Vit Ondruch) * Status: Closed * Priority: Normal * ruby -v: ruby 3.0.3p157 (2021-11-24 revision 3fb7d2cadc) [x86_64-linux] * Backport: 3.0: REQUIRED, 3.1: REQUIRED, 3.2: REQUIRED ---------------------------------------- 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 ~~~ -- https://bugs.ruby-lang.org/

1 0

[ruby-core:114811] [Ruby master Bug#18257] rb_mRubyVMFrozenCore is broken by GC run
by vo.x (Vit Ondruch) 19 Sep '23

19 Sep '23

Issue #18257 has been updated by vo.x (Vit Ondruch). Thx a lot! ---------------------------------------- Bug #18257: rb_mRubyVMFrozenCore is broken by GC run https://bugs.ruby-lang.org/issues/18257#change-104658 * Author: vo.x (Vit Ondruch) * Status: Closed * Priority: Normal * ruby -v: ruby 3.0.3p157 (2021-11-24 revision 3fb7d2cadc) [x86_64-linux] * Backport: 3.0: REQUIRED, 3.1: REQUIRED, 3.2: REQUIRED ---------------------------------------- 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 ~~~ -- https://bugs.ruby-lang.org/

1 0

[ruby-core:113926] [Ruby master Bug#19735] Add support for UUID version 7
by nevans (Nicholas Evans) 19 Sep '23

19 Sep '23

Issue #19735 has been reported by nevans (Nicholas Evans). ---------------------------------------- Bug #19735: Add support for UUID version 7 https://bugs.ruby-lang.org/issues/19735 * Author: nevans (Nicholas Evans) * Status: Open * Priority: Normal * Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN ---------------------------------------- Although the specification for UUIDv7 is still in draft, the UUIDv7 algorithm has been stable as the RFC progresses to completion. Version 7 UUIDs can be very useful, because they are lexographically sortable, which can improve e.g: database index locality. See section 6.10 of the draft specification for further explanation: https://www.ietf.org/archive/id/draft-ietf-uuidrev-rfc4122bis-06.html ```ruby require 'random/formatter' Random.uuid_v7 # => "0188ca50-fcc0-7881-b5c5-6d55cd8fc373" Random.uuid_v7 # => "0188ca51-0069-7304-be2e-0c3cd908789b" Random.uuid_v7 # => "0188ca51-04aa-7b57-a6ec-c49573412a9d" Random.uuid_v7 # => "0188ca51-0853-7979-ae37-485460e9f4f1" # or prng = Random.new prng.uuid_v7 # => "0188ca51-5e72-7950-a11d-def7ff977c98" ``` PR here: https://github.com/ruby/ruby/pull/7953 -- https://bugs.ruby-lang.org/

3 4

[ruby-core:114702] [Ruby master Feature#19874] Re-introduce heap sort by pinned count prior to GC compaction
by eightbitraptor (Matthew Valentine-House) 18 Sep '23

18 Sep '23

Issue #19874 has been reported by eightbitraptor (Matthew Valentine-House). ---------------------------------------- Feature #19874: Re-introduce heap sort by pinned count prior to GC compaction https://bugs.ruby-lang.org/issues/19874 * Author: eightbitraptor (Matthew Valentine-House) * Status: Open * Priority: Normal ---------------------------------------- See Github PR: [#8420](https://github.com/ruby/ruby/pull/8420) <hr /> ## Introduction In Ruby 2.7 compaction was originally introduced as an experimental feature. There was no auto-compaction, and compaction had to be manually triggered using `GC.compact`. See [this commit](https://github.com/ruby/ruby/commit/3ef4db15e95740839a0ed6d0224b2c9…. When this happened, at the start of compaction the heap was sorted so that pages containing the [most pinned slots were compacted into by default](https://github.com/ruby/ruby/commit/3ef4db15e95740839a0ed6d0224b2c…. This was important for compaction efficiency and copy on write friendliness as it prioritises filling pages that can't be free'd and emptying as many pages as possible. When `GC.auto_compact`, was introduced [in this commit](). This heap sorting mechanism was (unintentionally?) removed. This means that the heap is now unsorted when compacted and we're just compacting towards the lowest addresses from the higher ones. This PR re-introduces this feature: by default the heap will now be sorted by pinned object count prior to compaction. This will improve the CoW friendliness of compaction to aid the reforking work being carried out by byroot. ## Verifying the behaviour We used a test script to build a heap that would be laid out in a prescribed manner. with a predictable pinning pattern in order to test that pages with higher numbers of pinned objects are being filled first during compaction. Test script was as follows: ``` require 'fiddle' require 'objspace' objcount = 1_000_000 GC.disable list = [] # Create sparsely populated pages 32000.times do list << Object.new Object.new Object.new Object.new Object.new Object.new Object.new end # less sparsely populated pages 32000.times do list << Object.new Object.new Object.new Object.new end # densly populated pages 32000.times do list << Object.new Object.new end # packed pages 32000.times do list << Object.new end # Pin the set of objects and free the rest in order to create our controlled heap pinned = list.map { |x| Fiddle::Pinned.new(x) } GC.start # Dump the heap before compaction, this should contain lots of pages that contain # only pinned slots, in varying density patterns, followed by a solid chunk of # movable objects in the 40 byte size pool (these are the objects created by # `Fiddle::Pinned.new`). f = File.open("before.log", "w") ObjectSpace.dump_all(shapes: false, output: f) GC.compact GC.start puts `ps -o rss= -p #{$$}` # Dump the heap after compaction, this should show the same density pattern that we saw # in the previous dump, but this time the solid region of 40 byte objects should be compacted # into the pages with the most pinned objects first f = File.open("after.log", "w") ObjectSpace.dump_all(shapes: false, output: f) ``` ## Heap diagram before <img src="https://github.com/ruby/ruby/assets/31869/bffc0090-4790-477d-9476-bea5203fd…" width=400 /> This diagram shows heap pages vertically with the pinned object distribution pattern set up by the test script. ## Heap diagram after (master branch) <img src="https://github.com/ruby/ruby/assets/31869/3d3b8ff5-1625-4e05-b832-95d28f1a2…" width=400 /> This diagram shows the heap having been compacted without this patch. We can see that the heap has not been sorted by pages, and that movable objects (green) are being compacted into pages that contain fewer pinned objects, and leaving pages that contain lots of pinned objects sparsely populated. ## Heap diagram after (this branch) <img src="https://github.com/ruby/ruby/assets/31869/5ebdd282-b167-4ae4-b718-15fb095cf…" width=400 /> This diagram shows the heap having been compacted into pinned pages. This diagram shows pages sorted by their order in the `heap->pages` list. So will respect the sorting that happens during compaction. ## Benchmarking ### Compaction speed This plot shows mean and standard deviation of `GC.compact` time for 6 runs of the test script defined above on both this branch and master. Measured using `Benchmark.bm` <img src="https://github.com/ruby/ruby/assets/31869/fbe23946-08dd-4d8f-890c-5ab9be2dd…" width=640 /> Raw values are: | branch name | mean | std deviation | | ----------- | ------------ | ------------- | | this branch | 0.0125643333 | 0.0004797644 | | master | 0.0121891667 | 0.0008149953 | This data appears shows a 3% slowdown in GC compation times on this branch which is expected given the extra work required to sort the heap prior to compaction. However, given the sizeable overlap in the error bars we can conclude that this difference is not significant. ### Post compaction RSS We used a modified test script that created a heap with a lot of pinned slots at the end of the heap. The expected outcome is that if the heap remains unsorted, RSS will be higher because objects will be packed into the front of the heap, and then followed by sparsely populated pages of pinned objects. In a sorted heap, the objects will be packed in around the pages of pinned objects where possible allowing more empty pages to be free'd and RSS to be lower. Here is the test script used: ``` require 'fiddle' GC.disable list = [] 288000.times do Object.new end 36000.times do list << Object.new 50.times do Object.new end end pinned = list.map { |x| Fiddle::Pinned.new(x) } GC.start GC.compact puts `ps -o rss= -p #{$$}` ``` And here is the outcome: <img src="https://github.com/ruby/ruby/assets/31869/96716838-4d81-41fd-a91f-4704bed92…" width=640 /> Raw data: | branch name | mean | std deviation | | ----------- | ---------- | ------------- | | this branch | 92200.0000 | 332.9769 | | master | 93594.6667 | 188.9536 | We can see from this data that sorting the heap by pinned pages results in a 1.5% decrease in memory usage, and we can infer from the non-overlapping error bars that this is likely to be statistically significant. ## Conclusion Re-introducing heap sorting by pinned slots prior to compaction improves memory usage of a Ruby process by a statistically significant amount. It does this at a very slight, and likely insignificant performance penalty, which we believe to be acceptable given that GC compaction is currently a fairly major "stop the world" event that should only be done occasionally. For example, before forking. -- https://bugs.ruby-lang.org/

1 1

[ruby-core:114795] [Ruby master Bug#19888] Can't change binding of a Proc coerced from a Method
by waiting_for_dev 18 Sep '23

18 Sep '23

Issue #19888 has been reported by waiting_for_dev (Marc Busqué). ---------------------------------------- Bug #19888: Can't change binding of a Proc coerced from a Method https://bugs.ruby-lang.org/issues/19888 * Author: waiting_for_dev (Marc Busqué) * Status: Open * Priority: Normal * Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN ---------------------------------------- `instance_exec` or `instance_eval` can execute a given `Proc` in the context of the receiver. However, that's not true when the `Proc` has been coerced from a `Method`. In that situation, the binding is always tied to the original instance. ```ruby class A def foo "from A" end end class B def foo "from B" end end A.new.instance_exec(&-> { foo }) # => from A A.new.instance_exec(&B.new.method(:foo)) # => from B A.new.instance_exec(&B.new.method(:foo).to_proc) # => from B ``` At first sight, that looks like a bug, as the transformation from `Method` to `Proc` is not complete. -- https://bugs.ruby-lang.org/

2 1

[ruby-core:114794] [Ruby master Bug#17263] Fiber context switch degrades with number of fibers, limit on number of fibers
by kjtsanaktsidis (KJ Tsanaktsidis) 18 Sep '23

18 Sep '23

Issue #17263 has been updated by kjtsanaktsidis (KJ Tsanaktsidis). File flamegraph_make_many_fibers.png added File cache_misses_vs_time.png added OK, so I spent way longer than I should have staring at this but I think I've worked out what's going on. There are a couple of separate fibers to unpick here (ba-dum tish); I'll look at making fibers and switching between fibers as separate issues. ## Making lots of fibers Firstly, the process of making lots of fibers (and switching to them for the first time) is kind of slow. To see what's going on here, I made the following script `make_many_fibers.rb: ```ruby # make_many_fibers.rb GC.disable MAX = 2**20 FIBERS = [] MAX.times do fiber = Fiber.new do loop do Fiber.yield end end fiber.resume FIBERS << fiber end ``` And then ran it under perf to generate a combined userspace/kernelspace flamegrah: ``` sudo swapoff --all # make sure we don't get page faults from swap echo madvise | sudo tee /sys/kernel/mm/transparent_hugepage/enable # make sure THP doesn't cause faults echo -1 | sudo tee /proc/sys/kernel/perf_event_paranoid # allow unprivileged users to run perf echo 1000000000 | sudo tee /proc/sys/vm/max_map_count # boost mapping count % ruby --version ruby 3.3.0dev (2023-09-05T08:35:28Z master 5b146eb5a1) [x86_64-linux] perf record -F 999 -g -- ruby make_many_fibers.rb perf script report flamegraph ``` ![](flamegraph_make_many_fibers.png) (Also you can look at the [interactive HTML version](https://gistpreview.github.io/?1eef2ef1e521742c9f7778a14483d939)) You can see almost all of the time spent in the process of making fibers is in the kernel. A few things jump out at me. ### Fiber memory mappings Firstly, let's discuss the process of how memory is mapped for the fibers, in `fiber_pool_expand`. The code for this makes a single call to `mmap(2)` to produce a mapping large enough to hold a pool of fibers (up to 1024) - this happens in [fiber_pool_allocate_memory]https://github.com/ruby/ruby/blob/c87f2a4f156477…) Then, we divide up that space for each fiber in [fiber_pool_expand](https://github.com/ruby/ruby/blob/c87f2a4f156477ba962de1…. Each fiber gets an area for its Ruby stack, for its C stack, and a "guard page" below the stack so that a fiber which tries to grow its native stack out of bounds generates a page fault instead of trashing some random memory. That guard page is marked non-readable and non-writable through a call to `mprotect(2)` [here](https://github.com/ruby/ruby/blob/c87f2a4f156477ba962de19866a1f6298d5…. Despite this starting out as one mapping, on Linux a single memory mapping must actually have the same permissions for _all pages_ in the mapping. Thus, when a page inside a mapping has its protection flags changed, the mapping must actualy be split up into three; an area before the page being changed, a mapping containing just the page being changed, and the area afterwards. We can see in the flamegraph that a huge amount of kernel time is spent in the call to `mprotect`, doing `__split_vma`. Since we know ahead of time what the layout of the fiber pool's mappings is going to be, it might be worth experimenting with explicitly making two `mmap` calls per fiber; one to set up the memory needed, and one with the guard page. This would avoid the continous splitting as we `mprotect` the guard pages inside the one mapping. Another thing we could try here is using mmap's `MAP_GROWSDOWN` option instead of explicitly making guard pages ourselves. The [docs](https://man7.org/linux/man-pages/man2/mmap.2.html) say that "this flag is used for stacks" and automatically allocates a guard page which will attempt to grow the mapping if hit. I haven't looked too hard at how it's implemented, but it might mean we can use a _single_ mapping per fiber, with the guard page managed by the kernel. ### Page faults The second place we see a ton of kernel time being spent is in the page fault handler. This happens because when the mapping is created with `mmap`, the kernel doesn't actually back it with any memory; instead, it lazily waits for the application to try and access the memory range and only makes real memory available to the application then. We hit the page fault handler in two main places; `coroutine_initialize` (this is where the fiber's C stack is used for the first time), and `vm_push_frame` (this is where the fibers Ruby stack is used for the first time). This is why, in the profile @ioquatix shared before, we see more time in `vm_push_frame`. Each fibers first call to this method takes longer because it needs to allocate the initial page of Ruby stack. The original script in this issue makes more of the calls to `vm_push_frame` the initial call for a fiber because it has more fibers & the same number of iterations. There isn't a whole lot which can be done about this overhead unfortunately. The only thing which would really make a difference here is using `MAP_LOCKED` to eagerly allocate all the real memory when the mapping is first made, but that would be extrodinarily wasteful of real system memory. ## Transfering between existing fibers Once the fibers are all created (and used for the first time, to fault in the stack), the assertion in the original issue is that it should be a constant-time operation to transfer between fibers, irrespective of tthe number of fibers in the application. However, the script in @ioquatix's last comment shows the rate of fiber-transfer operations dropping off as more fibers participate in the benchmark. To debug this issue, I modified @ioquatix's script slightly to measure some performance counters with `perf` for each of the test iterations: ```ruby # transfer_many_fibers.rb require 'open3' require 'json' require 'csv' # This program shows how the performance of Fiber.transfer degrades as the fiber # count increases MAX = 2**20 FIBERS = [] MAX.times do fiber = Fiber.new do loop do Fiber.yield end end fiber.resume FIBERS << fiber end REPEATS = 10_000_000 PERF_COUNTERS = [ 'page-faults', 'major-faults', 'minor-faults', 'cpu-cycles:u', 'cpu-cycles:k', 'cache-misses', 'cache-references', 'L1-dcache-load-misses', 'L1-dcache-loads' ,'LLC-load-misses', 'LLC-loads', 'dTLB-loads', 'dTLB-load-misses', 'dTLB-stores', 'dTLB-store-misses' ] def with_perf_counters perf_cmd = [ 'perf', 'stat', '-e', PERF_COUNTERS.join(','), '-j', '-p', Process.pid.to_s, '-o', '/proc/self/fd/1' ] Open3.popen2(*perf_cmd) do |stdin, stdout, wait_thr| block_result = yield Process.kill :SIGINT, wait_thr.pid counters = {} stdout.each_line do |ln| parsed_ln = JSON.parse ln counters[parsed_ln['event']] = parsed_ln['counter-value'].to_i end wait_thr.value return [block_result, counters] end end def run(fibers, repeats = REPEATS) count = 0 t0 = Process.clock_gettime(Process::CLOCK_MONOTONIC) while count < repeats fibers.each do |fiber| count += 1 break if count >= repeats fiber.resume end end elapsed = Process.clock_gettime(Process::CLOCK_MONOTONIC) - t0 end # Print results as a CSV table: puts CSV.generate_line [ 'fibers', 'elapsed time (s)', 'rate (t/s)', *PERF_COUNTERS ] GC.disable 21.times do |i| GC.start limit = 2**i fibers = FIBERS[0...limit] elapsed, perf_counters = with_perf_counters { run(fibers) } rate = REPEATS / elapsed puts CSV.generate_line [ limit, elapsed, rate, *PERF_COUNTERS.map { perf_counters[_1] }, ] end ``` This generats a table like the previous comment, but also includes performance counter information from `perf`. I ran this as follows: ``` sudo swapoff --all # make sure we don't get page faults from swap echo madvise | sudo tee /sys/kernel/mm/transparent_hugepage/enable # make sure THP doesn't cause faults echo -1 | sudo tee /proc/sys/kernel/perf_event_paranoid # allow unprivileged users to run perf echo 1000000000 | sudo tee /proc/sys/vm/max_map_count # boost mapping count % ruby --version ruby 3.3.0dev (2023-09-05T08:35:28Z master 5b146eb5a1) [x86_64-linux] ruby transfer_many_fibers.rb ``` and obtained the following CSV data as a result: ``` fibers,elapsed time (s),rate (t/s),page-faults,major-faults,minor-faults,cpu-cycles:u,cpu-cycles:k,cache-misses,cache-references,L1-dcache-load-misses,L1-dcache-loads,LLC-load-misses,LLC-loads,dTLB-loads,dTLB-load-misses,dTLB-stores,dTLB-store-misses 1,1.4039703360003841,7122657.611476247,3,0,3,5859475245,12694559,3387,54987,165432,7146119413,650,16262,7145394321,4252,4601866193,7320 2,1.2886379399997168,7760131.600659063,1,0,1,5439823427,11350600,5964,55424,189086,6621658447,500,15200,6622892928,5438,4258132955,6574 4,1.258153214000231,7948157.576298307,0,0,0,5310310212,13089610,10449,68069,294892,6335968536,290,16860,6345118100,25997,4058742655,6802 8,1.253403425000215,7978277.225465762,0,0,0,5279962922,34494806,5446,51855,62076301,6192431913,900,16039,6179777983,44444,3939369328,6815 16,1.2689530819998254,7880512.007772858,0,0,0,5370474254,10763313,3844,47457,183940406,6102241668,765,16165,6103205916,26204,3910352255,6246 32,1.2346172180004942,8099676.445623648,0,0,0,5332621133,15694092,10154,64114,200680305,6063273925,462,15166,6068903340,38317,3883690997,11413 64,1.2704579209994336,7871177.655481325,0,0,0,5346794521,12588604,9447,56960,232002452,6059702410,638,15011,6058457551,17290,3878188080,8864 128,1.26315632800015,7916676.485983461,0,0,0,5343576341,12619817,30122,172656,254975275,6032357554,781,28931,6043258633,16401,3866060907,7708 256,1.3926949320002677,7180323.393320194,1,0,1,5946049052,16997016,232957,228631165,263358837,6037282294,1965,49843868,6038606356,14063,3867631144,7523 512,1.4688533830003507,6808031.431682799,0,0,0,6499307194,16462834,1098041,459635153,271677968,6042696127,5034,97729427,6041134724,1340316,3870403582,913873 1024,1.6829085890003626,5942093.388411512,0,0,0,7586548807,18469725,17423890,505379678,289076442,6049202803,558254,99886434,6055483248,10667121,3875545360,8659232 2048,2.458299625000109,4067852.3880096828,0,0,0,10614911431,34628829,125912094,586214908,293999643,6065587295,9686614,109485434,6074510477,12782326,3886950850,9275023 4096,3.8801752910003415,2577203.154505403,0,0,0,14523389421,54902097,332459456,565424689,294461987,6081202395,72540001,112161028,6082385994,18416444,3895766223,3191327 8192,4.739300166999783,2110016.172773987,0,0,0,16748731849,80070197,433472922,584586094,293148050,6082602630,93201829,114523043,6098901364,17956895,3898469812,4034203 16384,5.312199805000091,1882459.313858551,0,0,0,18067407945,89930922,494108236,594290763,292332035,6085798157,104621395,114785396,6094092659,17858483,3896705126,4349967 32768,5.714678685999388,1749879.6606884277,0,0,0,18954140751,57310406,520112168,600784408,292360264,6087857552,110260489,114733525,6089971523,17990727,3897881974,4273404 65536,5.85913169899959,1706737.5361621308,0,0,0,19225994828,58272894,527013755,601246452,292342290,6087916819,111582260,114827548,6091113925,18252983,3898391171,4059701 131072,5.90900381099982,1692332.6367440557,0,0,0,19223289411,60175735,530254916,600266994,292030029,6085240814,111810664,114751374,6084010298,18191953,3891766484,4108941 262144,5.8664713339994705,1704602.2098573,0,0,0,19168022353,66616904,531536818,601173015,291660876,6086962661,111537615,114434876,6090071817,17934617,3900912972,4454238 524288,5.871122640999602,1703251.7648613497,0,0,0,19239854173,74336965,531516412,601003077,291588311,6087162576,111521049,114462843,6092648529,17901966,3902304196,4484503 1048576,5.919364534000124,1689370.5299886826,0,0,0,19290077173,162339116,532576986,603934645,291400193,6088300500,111567224,114528793,6087885216,17794051,3898248975,4611646 ``` ### Page faults Firstly, the number of page faults in the transfer process is zero. This is expected; each of these fibers was already resumed once at the top of the script, so their stacks are faulted in. Thus, transferring between them incurs no page fault. (sidebar: My initial version of this test actually _did_ generate a large number of page faults. Eventually, I worked out it was because I was running the script as root. Ruby's `Process.spawn` uses `vfork(2)` to create the new process to be executed normally, BUT it uses `fork(2)` when the process is privileged. When you use real fork to make a new process, Linux marks all of your memory pages as read-only, so they can be shared with the just-forked process with copy-on-write semantics - even though the child process calls `exec(2)` straight afterwards! The next time your process tries to write to a page, it takes a page fault. The fault handler works out that the page is no longer shared (since the child process exec'd) and marks it as writable again. Anyway I spent _hours_ trying to find out where these faults were coming from... glad I did though!) ### Cache misses Based on this data, my assessment is that the scenarios with more fibers involved in the transfer dance are slower because they put more pressure on the CPU's various caches. It's quite confusing what all the various cache measurements mean, but I think the `cache-misses` metric measures all memory accesses which missed _all_ the caches, based on [this Stackoverflow answer](https://stackoverflow.com/questions/55035313/how-does-linux-perf-ca…. It seems that the overall time spent on the benchmark is _very_ strongly correlated to the total `cache-misses`: ![](cache_misses_vs_time.png) Based on this, I believe transfering between multiple fibers in this benchmark gets slower because each fiber has its stack in a different part of the system's memory, and so with many fibers you're far less likely to get a CPU cache hit when loading that fibers stack. I don't think there's _really_ anything which can be done here; working on large amounts of data or instructions which don't fit into CPU cache is _always_ much slower than smaller bits which do. This benchmark is particuarly pathalogical because all it does is flip between fibers; in a real application hopfully the CPU caches would quickly be filled up with some relevant data for the fiber that's running. ## Conclusion I think it's worth experimenting with manually making a single `MAP_GROWSDOWN` mapping per fiber to see if that can improve fiber creation time by avoiding having the kernel split the mappings sequentially. However, I don't think there's a real problem with fiber transfers once the fibers have been created. ---------------------------------------- Bug #17263: Fiber context switch degrades with number of fibers, limit on number of fibers https://bugs.ruby-lang.org/issues/17263#change-104638 * Author: ciconia (Sharon Rosner) * Status: Closed * Priority: Normal * ruby -v: 2.7.1 * Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN ---------------------------------------- I'm working on developing [Polyphony](https://github.com/digital-fabric/polyphony), a Ruby gem for writing highly-concurrent Ruby programs with fibers. In the course of my work I have come up against two problems using Ruby fibers: 1. Fiber context switching performance seem to degrade as the number of fibers is increased. This is both with `Fiber#transfer` and `Fiber#resume/Fiber.yield`. 2. The number of concurrent fibers that can exist at any time seems to be limited. Once a certain number is reached (on my system this seems to be 31744 fibers), calling `Fiber#transfer` will raise a `FiberError` with the message `can't set a guard page: Cannot allocate memory`. This is not due to RAM being saturated. With 10000 fibers, my test program hovers at around 150MB RSS (on Ruby 2.7.1). Here's a program for testing the performance of `Fiber#transfer`: ```ruby # frozen_string_literal: true require 'fiber' class Fiber attr_accessor :next end def run(num_fibers) count = 0 GC.start GC.disable first = nil last = nil supervisor = Fiber.current num_fibers.times do fiber = Fiber.new do loop do count += 1 if count == 1_000_000 supervisor.transfer else Fiber.current.next.transfer end end end first ||= fiber last.next = fiber if last last = fiber end last.next = first t0 = Time.now first.transfer elapsed = Time.now - t0 rss = `ps -o rss= -p #{Process.pid}`.to_i puts "fibers: #{num_fibers} rss: #{rss} count: #{count} rate: #{count / elapsed}" rescue Exception => e puts "Stopped at #{count} fibers" p e end run(100) run(1000) run(10000) run(100000) ``` With Ruby 2.6.5 I'm getting: ``` fibers: 100 rss: 23212 count: 1000000 rate: 3357675.1688139187 fibers: 1000 rss: 31292 count: 1000000 rate: 2455537.056439736 fibers: 10000 rss: 127388 count: 1000000 rate: 954251.1674325482 Stopped at 22718 fibers #<FiberError: can't set a guard page: Cannot allocate memory> ``` With Ruby 2.7.1 I'm getting: ``` fibers: 100 rss: 23324 count: 1000000 rate: 3443916.967616508 fibers: 1000 rss: 34676 count: 1000000 rate: 2333315.3862491543 fibers: 10000 rss: 151364 count: 1000000 rate: 916772.1008060966 Stopped at 31744 fibers #<FiberError: can't set a guard page: Cannot allocate memory> ``` With ruby-head I get an almost identical result to that of 2.7.1. As you can see, the performance degradation is similar in all the three versions of Ruby, going from ~3.4M context switches per second for 100 fibers to less then 1M context switches per second for 10000 fibers. Running with 100000 fibers fails to complete. Here's a program for testing the performance of `Fiber#resume/Fiber.yield`: ```ruby # frozen_string_literal: true require 'fiber' class Fiber attr_accessor :next end # This program shows how the performance of Fiber.transfer degrades as the fiber # count increases def run(num_fibers) count = 0 GC.start GC.disable fibers = [] num_fibers.times do fibers << Fiber.new { loop { Fiber.yield } } end t0 = Time.now while count < 1000000 fibers.each do |f| count += 1 f.resume end end elapsed = Time.now - t0 puts "fibers: #{num_fibers} count: #{count} rate: #{count / elapsed}" rescue Exception => e puts "Stopped at #{count} fibers" p e end run(100) run(1000) run(10000) run(100000) ``` With Ruby 2.7.1 I'm getting the following output: ``` fibers: 100 count: 1000000 rate: 3048230.049946255 fibers: 1000 count: 1000000 rate: 2362235.6455160403 fibers: 10000 count: 1000000 rate: 950251.7621725246 Stopped at 21745 fibers #<FiberError: can't set a guard page: Cannot allocate memory> ``` As I understand it, theoretically at least switching between fibers should have a constant cost in terms of CPU cycles, irrespective of the number of fibers currently existing in memory. I am completely ignorant the implementation details of Ruby fibers, so at least for now I don't have any idea where this problem is coming from. ---Files-------------------------------- clipboard-202308251514-grqb1.png (81.3 KB) clipboard-202308251514-r7g4l.png (81 KB) clipboard-202308251538-kmofk.png (13.8 KB) flamegraph_make_many_fibers.png (471 KB) cache_misses_vs_time.png (42.5 KB) -- https://bugs.ruby-lang.org/

1 0