https://redmine.ruby-lang.org/https://redmine.ruby-lang.org/favicon.ico?17113305112018-06-08T05:13:49ZRuby Issue Tracking SystemRuby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=724422018-06-08T05:13:49Zkivikakk (Ashe Connor)
<ul></ul><p>It's also worth noting:</p>
<ul>
<li>is the increment of <code>pc</code> with <code>ec->cfp->pc++</code> correct? What if the instruction is multiple values wide?</li>
<li>there are similar <code>pc</code> increment/decrement pairs around <code>EXEC_EVENT_HOOK</code> calls in <code>vm_trace</code>. Do we need to address these too?</li>
</ul>
<p>Ping <a class="user active user-mention" href="https://redmine.ruby-lang.org/users/73">@tenderlovemaking (Aaron Patterson)</a> as he helped me with this.</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=724432018-06-08T05:44:31Zkivikakk (Ashe Connor)
<ul></ul><p>Further:</p>
<ul>
<li>is the original change correct? Some instructions have the <code>handle_frame?</code> property, which means they <em>do</em> increment the PC by the instruction width first. It's those that don't have that property which now increment the PC after. The gc hook caller always increments PC, assuming non-<code>handle_frame?</code> instructions.</li>
</ul> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=724452018-06-08T08:13:04Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul><li><strong>Status</strong> changed from <i>Open</i> to <i>Assigned</i></li><li><strong>Assignee</strong> set to <i>shyouhei (Shyouhei Urabe)</i></li></ul><p>Thanks reporting! Will handle it.</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=726502018-06-25T05:47:36Zkivikakk (Ashe Connor)
<ul></ul><p>Here's an easy way to reproduce the segfault on current trunk:</p>
<p><code>Gemfile</code></p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="n">source</span> <span class="s2">"https://rubygems.org"</span>
<span class="n">gem</span> <span class="s2">"stackprof"</span>
</code></pre>
<p><code>test.rb</code></p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="nb">require</span> <span class="s1">'stackprof'</span>
<span class="no">StackProf</span><span class="p">.</span><span class="nf">run</span><span class="p">(</span><span class="ss">mode: :object</span><span class="p">)</span> <span class="k">do</span>
<span class="p">[</span><span class="mi">123</span><span class="p">].</span><span class="nf">group_by</span> <span class="p">{}</span>
<span class="k">end</span>
</code></pre>
<p>Output:</p>
<pre><code>$ ruby test.rb
test.rb:4: [BUG] Segmentation fault at 0x0000000000000000
ruby 2.6.0dev (2018-06-25 trunk 63747) [x86_64-linux]
-- Control frame information -----------------------------------------------
c:0007 p:---- s:0024 e:000023 IFUNC
c:0006 p:---- s:0021 e:000020 CFUNC :each
c:0005 p:---- s:0018 e:000017 CFUNC :group_by
c:0004 p:0007 s:0014 e:000013 BLOCK test.rb:4 [FINISH]
c:0003 p:---- s:0011 e:000010 CFUNC :run
c:0002 p:0020 s:0006 e:000005 EVAL test.rb:3 [FINISH]
c:0001 p:0000 s:0003 E:002330 (none) [FINISH]
-- Ruby level backtrace information ----------------------------------------
test.rb:3:in `<main>'
test.rb:3:in `run'
test.rb:4:in `block in <main>'
test.rb:4:in `group_by'
test.rb:4:in `each'
Segmentation fault
</code></pre>
<p>When using gdb:</p>
<pre><code>$ gdb -q --args `rbenv which ruby` test.rb
Reading symbols from /home/kivikakk/.rbenv/versions/ruby-trunk/bin/ruby...done.
(gdb) run
Starting program: /home/kivikakk/.rbenv/versions/ruby-trunk/bin/ruby test.rb
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff7ff4700 (LWP 23118)]
Program received signal SIGSEGV, Segmentation fault.
0x00005555555c84ef in succ_index_lookup (sd=0xe0458d48e0458948, x=-454013225) at iseq.c:3089
3089 return imm_block_rank_get(sd->imm_part[i], j);
(gdb) bt 30
#0 0x00005555555c84ef in succ_index_lookup (sd=0xe0458d48e0458948, x=-454013225) at iseq.c:3089
#1 0x00005555555c2c3f in get_insn_info_succinct_bitvector (iseq=0x555555cd0b18, pos=428210124447829719) at iseq.c:1522
#2 0x00005555555c2c7b in get_insn_info (iseq=0x555555cd0b18, pos=428210124447829719) at iseq.c:1530
#3 0x00005555555c2ca0 in rb_iseq_line_no (iseq=0x555555cd0b18, pos=428210124447829719) at iseq.c:1598
#4 0x000055555571a13e in calc_lineno (iseq=0x555555cd0b18, pc=0x8) at vm_backtrace.c:37
#5 0x000055555571c1ec in rb_profile_frames (start=0, limit=2048, buff=0x7ffff6740530 <_stackprof+176>, lines=0x7ffff6744530 <_stackprof+16560>) at vm_backtrace.c:1295
#6 0x00007ffff653ee12 in stackprof_record_sample () at stackprof.c:484
#7 0x00007ffff653efe7 in stackprof_job_handler (data=0x0) at stackprof.c:539
#8 0x00007ffff653f0d3 in stackprof_newobj_handler (tpval=93825000082360, data=0x0) at stackprof.c:561
#9 0x000055555572086d in tp_call_trace (tpval=93825000082360, trace_arg=0x7fffffffb440) at vm_trace.c:1077
#10 0x000055555571ed6e in exec_hooks_body (ec=0x555555acf8c8, list=0x555555acf340, trace_arg=0x7fffffffb440) at vm_trace.c:272
#11 0x000055555571ee65 in exec_hooks_unprotected (ec=0x555555acf8c8, vm=0x555555acef20, list=0x555555acf340, trace_arg=0x7fffffffb440) at vm_trace.c:301
#12 0x000055555571f0ab in rb_exec_event_hooks (trace_arg=0x7fffffffb440, pop_p=0) at vm_trace.c:345
#13 0x00005555555895cc in rb_exec_event_hook_orig (ec=0x555555acf8c8, flag=1048576, self=93825000082320, id=0, called_id=0, klass=0, data=93825000082120, pop_p=0) at vm_core.h:1778
#14 0x000055555558afb7 in gc_event_hook_body (ec=0x555555acf8c8, objspace=0x555555acf650, event=1048576, data=93825000082120) at gc.c:1810
#15 0x000055555558b242 in newobj_slowpath (klass=93824998289320, flags=8199, v1=0, v2=0, v3=0, objspace=0x555555acf650, wb_protected=1) at gc.c:1924
#16 0x000055555558b294 in newobj_slowpath_wb_protected (klass=93824998289320, flags=8199, v1=0, v2=0, v3=0, objspace=0x555555acf650) at gc.c:1934
#17 0x000055555558b3c9 in newobj_of (klass=93824998289320, flags=8199, v1=0, v2=0, v3=0, wb_protected=1) at gc.c:1966
#18 0x000055555558b462 in rb_wb_protected_newobj_of (klass=93824998289320, flags=8199) at gc.c:1982
#19 0x0000555555727121 in ary_alloc (klass=93824998289320) at array.c:437
#20 0x00005555557271b4 in ary_new (klass=93824998289320, capa=1) at array.c:466
#21 0x00005555557274bb in rb_ary_tmp_new_from_values (klass=93824998289320, n=1, elts=0x7fffffffb700) at array.c:514
#22 0x00005555557275ae in rb_ary_new_from_values (n=1, elts=0x7fffffffb700) at array.c:526
#23 0x000055555578bf1c in group_by_i (i=247, hash=93825000082280, argc=1, argv=0x7fffffffb868, blockarg=8) at enum.c:894
#24 0x00005555557006cf in vm_yield_with_cfunc (ec=0x555555acf8c8, captured=0x7ffff6e53f10, self=93825000082320, argc=1, argv=0x7fffffffb868, block_handler=0) at vm_insnhelper.c:2569
#25 0x0000555555714697 in invoke_block_from_c_bh (ec=0x555555acf8c8, block_handler=140737335607059, argc=1, argv=0x7fffffffb868, passed_block_handler=0, cref=0x0, is_lambda=0,
force_blockarg=0) at vm.c:1079
#26 0x00005555557147f7 in vm_yield (ec=0x555555acf8c8, argc=1, argv=0x7fffffffb868) at vm.c:1119
#27 0x000055555571050e in rb_yield_0 (argc=1, argv=0x7fffffffb868) at vm_eval.c:972
#28 0x000055555571052d in rb_yield_1 (val=247) at vm_eval.c:978
#29 0x000055555571055f in rb_yield (val=247) at vm_eval.c:988
(More stack frames follow...)
</code></pre> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=726672018-06-27T00:15:22Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul><li><strong>Related to</strong> <i><a class="issue tracker-1 status-5 priority-4 priority-default closed" href="/issues/14809">Bug #14809</a>: calc_lineno() returns wrong location</i> added</li></ul> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=726682018-06-27T00:16:05Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul></ul><p>This issue and <a class="issue tracker-1 status-5 priority-4 priority-default closed" title="Bug: calc_lineno() returns wrong location (Closed)" href="https://redmine.ruby-lang.org/issues/14809">#14809</a> are caused by the same problem.</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=726762018-06-27T09:28:15Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul><li><strong>Status</strong> changed from <i>Assigned</i> to <i>Closed</i></li></ul><p>Applied in changeset trunk|r63763.</p>
<hr>
<p>give up insn attr handles_frame</p>
<p>I introduced this mechanism in r62051 to speed things up. Later it<br>
was reported that the change causes problems. I searched for<br>
workarounds but nothing seemed appropriate. I hereby officially<br>
give it up. The idea to move ADD_PC around was a mistake.</p>
<p>Fixes [Bug <a class="issue tracker-1 status-5 priority-4 priority-default closed" title="Bug: calc_lineno() returns wrong location (Closed)" href="https://redmine.ruby-lang.org/issues/14809">#14809</a>] and [Bug <a class="issue tracker-1 status-5 priority-4 priority-default closed" title="Bug: rb_profile_frames SEGV when PC adjusted on IFUNC (Closed)" href="https://redmine.ruby-lang.org/issues/14834">#14834</a>].</p>
<p>Signed-off-by: Urabe, Shyouhei <a href="mailto:shyouhei@ruby-lang.org" class="email">shyouhei@ruby-lang.org</a></p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=802852019-07-30T16:04:21Zjhawthorn (John Hawthorn)
<ul><li><strong>Status</strong> changed from <i>Closed</i> to <i>Open</i></li></ul><p>I believe since r64737 this is an issue again.</p>
<p>On Ruby 2.6.3 I get an almost identical stacktrace as before</p>
<pre><code>Thread 1 "ruby" received signal SIGSEGV, Segmentation fault.
0x00005555555cac9e in succ_index_lookup (x=<optimized out>, sd=0x10c483485c750000) at iseq.c:3357
3357 return imm_block_rank_get(sd->imm_part[i], j);
(gdb) bt
#0 0x00005555555cac9e in succ_index_lookup (x=<optimized out>, sd=0x10c483485c750000) at iseq.c:3357
#1 get_insn_info_succinct_bitvector (iseq=<optimized out>, pos=<optimized out>) at iseq.c:1593
#2 get_insn_info (pos=<optimized out>, iseq=<optimized out>) at iseq.c:1601
#3 rb_iseq_line_no (iseq=<optimized out>, pos=<optimized out>) at iseq.c:1669
#4 0x000055555571cf83 in calc_lineno (pc=<optimized out>, iseq=<optimized out>) at vm_backtrace.c:47
#5 rb_profile_frames (start=start@entry=0, limit=limit@entry=2048, buff=buff@entry=0x7fffffff86f0,
lines=lines@entry=0x7fffffff66f0) at vm_backtrace.c:1308
#6 0x00007ffff5532e83 in newobj (tpval=<optimized out>, ptr=0x555555feb610)
at ../../../../ext/allocation_sampler/allocation_sampler.c:227
#7 0x000055555571dc49 in tp_call_trace (tpval=<optimized out>, trace_arg=<optimized out>) at vm_trace.c:1194
#8 0x000055555571e206 in exec_hooks_body (ec=ec@entry=0x5555558c13b8, trace_arg=0x7fffffffc7d0, trace_arg@entry=0x7fffffffc790,
list=<optimized out>) at vm_trace.c:304
#9 0x0000555555720ebc in exec_hooks_unprotected (trace_arg=0x7fffffffc790, list=0x5555558c0e08, ec=<optimized out>)
at vm_trace.c:333
#10 rb_exec_event_hooks (trace_arg=trace_arg@entry=0x7fffffffc7d0, hooks=<optimized out>, pop_p=pop_p@entry=0) at vm_trace.c:378
#11 0x000055555558f72f in rb_exec_event_hook_orig (pop_p=0, data=<optimized out>, klass=0, called_id=0, id=0,
self=<optimized out>, flag=<optimized out>, hooks=<optimized out>, ec=0x5555558c13b8) at vm_core.h:1870
#12 gc_event_hook_body (ec=0x5555558c13b8, event=<optimized out>, data=<optimized out>, objspace=<optimized out>) at gc.c:1805
#13 0x0000555555599cf8 in newobj_slowpath (wb_protected=1, objspace=0x5555558c1140, v3=0, v2=<optimized out>, v1=0, flags=8199,
klass=<optimized out>) at vm_core.h:1735
#14 newobj_slowpath_wb_protected (klass=<optimized out>, flags=8199, v1=0, v2=<optimized out>, v3=0, objspace=0x5555558c1140)
at gc.c:1929
</code></pre> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=802982019-07-31T08:33:59Znagachika (Tomoyuki Chikanaga)nagachika00@gmail.com
<ul><li><strong>Backport</strong> changed from <i>2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: UNKNOWN</i> to <i>2.4: DONTNEED, 2.5: DONTNEED, 2.6: REQUIRED</i></li></ul> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=803232019-08-01T07:04:25Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul><li><strong>Status</strong> changed from <i>Open</i> to <i>Closed</i></li></ul><p>Applied in changeset <a class="changeset" title="fix tracepoint + backtrace SEGV PC modification in gc_event_hook_body was careless. There are (..." href="https://redmine.ruby-lang.org/projects/ruby-master/repository/git/revisions/5d33f787169bcc3594d2264726695d58c4a06899">git|5d33f787169bcc3594d2264726695d58c4a06899</a>.</p>
<hr>
<p>fix tracepoint + backtrace SEGV</p>
<p>PC modification in gc_event_hook_body was careless. There are (so<br>
to say) abnormal iseqs stored in the cfp. We have to check sanity<br>
before we touch the PC.</p>
<p>This has not been fixed because there was no way to (ab)use the<br>
setup from pure-Ruby. However by using our official C APIs it is<br>
possible to touch such frame(s), resulting in SEGV.</p>
<p>Fixes [Bug <a class="issue tracker-1 status-5 priority-4 priority-default closed" title="Bug: rb_profile_frames SEGV when PC adjusted on IFUNC (Closed)" href="https://redmine.ruby-lang.org/issues/14834">#14834</a>].</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=803242019-08-01T07:09:12Zshyouhei (Shyouhei Urabe)shyouhei@ruby-lang.org
<ul></ul><p>Yes indeed. I was wrong, and the analysis by the OP is basically right. Pushed 5d33f787169bcc3594d2264726695d58c4a06899 which I hope should fix the problem. Sorry for the trouble.</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=803332019-08-01T17:30:42Ztenderlovemaking (Aaron Patterson)tenderlove@ruby-lang.org
<ul></ul><p>Thanks for the fix <a class="user active user-mention" href="https://redmine.ruby-lang.org/users/10">@shyouhei (Shyouhei Urabe)</a>!</p> Ruby master - Bug #14834: rb_profile_frames SEGV when PC adjusted on IFUNChttps://redmine.ruby-lang.org/issues/14834?journal_id=808332019-08-18T06:10:51Znagachika (Tomoyuki Chikanaga)nagachika00@gmail.com
<ul><li><strong>Backport</strong> changed from <i>2.4: DONTNEED, 2.5: DONTNEED, 2.6: REQUIRED</i> to <i>2.4: DONTNEED, 2.5: DONTNEED, 2.6: DONE</i></li></ul><p>ruby_2_6 r67745 merged revision(s) 5d33f787169bcc3594d2264726695d58c4a06899,8b162ce9d1003e4e469d8f48cb9a2076fd45b47c.</p>