Bug #13566: A process freezes at the beginning of C level backtrace when a certain SEGV is occurred

• Status: Closed
• Assignee: naruse (Yui NARUSE)
• Target version: -
• ruby -v: ruby 2.4.1p111 (2017-03-22 revision 58053) [x86_64-darwin16]
• Backport: 2.2: REQUIRED, 2.3: DONE, 2.4: DONE

[mrkn (Kenta Murata)]

I found the issue that a process freezes at the beginning of C level backtrace printing when a certain SEGV is occurred.

I've made a reproducible code in the freeze_on_segv branch of pycall project.
You can check it by the following steps:

$ git clone [e-mail]:mrkn/pycall.git
$ git checkout -t origin/freeze_on_segv
$ bundle install
$ bin/runner callback.rb

When you succeed to reproduce the issue, you can see the following output:

$ bin/runner callback.rb
{:rw_refcnt=>1}
42
42
{:res=>42}
{#<FFI::Pointer address=0x00000109057d10>=>[#<Proc:[e-mail]:1>]}
callback.rb:11: [BUG] Segmentation fault at 0x00000000000000
ruby 2.4.1p111 (2017-03-22 revision 58053) [x86_64-darwin16]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   for more details.
Don't forget to include the above Crash Report log file in bug reports.

-- Control frame information -----------------------------------------------
c:0005 p:---- s:0021 e:000020 CFUNC  :Py_DecRef
c:0004 p:0105 s:0016 E:002530 TOP    callback.rb:11 [FINISH]
c:0003 p:---- s:0011 e:000010 CFUNC  :load
c:0002 p:0034 s:0006 e:000005 EVAL   bin/runner:6 [FINISH]
c:0001 p:0000 s:0003 E:0013a0 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
bin/runner:6:in `<main>'
bin/runner:6:in `load'
callback.rb:11:in `<top (required)>'
callback.rb:11:in `Py_DecRef'

-- Machine register context ------------------------------------------------
 rax: 0x00007fbb43667950 rbx: 0x729546a3ab9700ab rcx: 0x00007fbb40d05190
 rdx: 0x00007fbb40d05190 rdi: 0x0000000109057d10 rsi: 0x00007fbb411e0358
 rbp: 0x00007fff577eb6c0 rsp: 0x00007fff577eb6b8  r8: 0x00007fff577eb6e0
  r9: 0x00000001085e46a1 r10: 0x00007fff577eb610 r11: 0x0000000108ca1d30
 r12: 0x0000000000000000 r13: 0x0000000000000001 r14: 0x729546a3ab9700ab
 r15: 0x00007fff577eb7d0 rip: 0x0000000000000000 rfl: 0x0000000000010246

-- C level backtrace information -------------------------------------------

At this point, C-c doesn't work.

[mrkn (Kenta Murata)]

Note that I use CPython 3.6 that is built with --with-shared configure option.

[mrkn (Kenta Murata)]

I've confirmed that this issue isn't reproduced on x86_64-linux.

[wanabe (_ wanabe)]

mrkn (Kenta Murata) wrote:

r15: 0x00007fff577eb7d0 rip: 0x0000000000000000 rfl: 0x0000000000010246

rb_dump_machine_register() shows "rip: 0x0000000000000000".
And lldb on my environment shows that uctx->uc_mcontext->__ss.__rip[-2] is accessed by backtrace() in vm_dump.c. It makes main-thread stop by EXC_BAD_ACCESS.

$ lldb -p 936
(lldb) process attach --pid 936
Process 936 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0xfffffffffffffffe)
    frame #0: 0x0000000105ccb599 ruby`backtrace(trace=0x0000000105d69cd0, size=<unavailable>) at vm_dump.c:478
   475          unw_set_reg(&cursor, UNW_X86_64_R14, uctx->uc_mcontext->__ss.__r14);
   476          unw_set_reg(&cursor, UNW_X86_64_R15, uctx->uc_mcontext->__ss.__r15);
   477          ip = uctx->uc_mcontext->__ss.__rip;
-> 478          if (((char*)ip)[-2] == 0x0f && ((char*)ip)[-1] == 5) {
   479              /* signal received in syscall */
   480              trace[n++] = (void *)ip;
   481              ip = *(unw_word_t*)uctx->uc_mcontext->__ss.__rsp;

Executable module set to "/Users/wanabe/.rbenv/versions/trunk/bin/ruby".
Architecture set to: x86_64-apple-macosx.
(lldb) 

It seems to be related to #12711.

[wanabe (_ wanabe)]

• Related to Bug #12711: Darwin doesn't show C backtrace correctly if iSIGSEGV is received when IP is in userland added

[mrkn (Kenta Murata)]

A small code to reproduce this issue is here:

require 'fiddle'
Fiddle::Function.new(Fiddle::NULL, [], Fiddle::TYPE_VOID).call

[mrkn (Kenta Murata)]

I confirmed that it is reproducible on Ruby 2.3.3.

$ RBENV_VERSION=2.3.3 ruby -r fiddle -e 'Fiddle::Function.new(Fiddle::NULL, [], Fiddle::TYPE_VOID).call'
-e:1: [BUG] Segmentation fault at 0x00000000000000
ruby 2.3.3p222 (2016-11-21 revision 56859) [x86_64-darwin16]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/CrashReporter
     * /Library/Logs/CrashReporter
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   for more details.
Don't forget to include the above Crash Report log file in bug reports.

-- Control frame information -----------------------------------------------
c:0003 p:---- s:0007 e:000006 CFUNC  :call
c:0002 p:0037 s:0004 E:001370 EVAL   -e:1 [FINISH]
c:0001 p:0000 s:0002 E:001e70 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
-e:1:in `<main>'
-e:1:in `call'

-- Machine register context ------------------------------------------------
 rax: 0x0000000000000000 rbx: 0x00007fd196c064a0 rcx: 0x0000000000000000
 rdx: 0x0000000000000000 rdi: 0x0000000000000000 rsi: 0x0000000000000000
 rbp: 0x00007fff5bc7dce0 rsp: 0x00007fff5bc7dcd8  r8: 0x0000000000000000
  r9: 0x0000000000000000 r10: 0x00007fff5bc7dc30 r11: 0x0000000000000000
 r12: 0x00007fff5bc7dea0 r13: 0x0000000000000000 r14: 0xc922be45f27300e8
 r15: 0x00007fff5bc7deb8 rip: 0x0000000000000000 rfl: 0x0000000000010246

-- C level backtrace information -------------------------------------------
^Z
[1]+  Stopped                 RBENV_VERSION=2.3.3 ruby -r fiddle -e 'Fiddle::Function.new(Fiddle::NULL, [], Fiddle::TYPE_VOID).call'

[mrkn (Kenta Murata)]

It can be reproducible on Ruby 2.2.7, too.

$ RBENV_VERSION=2.2.7 ruby -rfiddle -e 'Fiddle::Function.new(Fiddle::NULL, [], Fiddle::TYPE_VOID).call'
-e:1: [BUG] Segmentation fault at 0x00000000000000
ruby 2.2.7p470 (2017-03-28 revision 58194) [x86_64-darwin16]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/CrashReporter
     * /Library/Logs/CrashReporter
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   for more details.

-- Control frame information -----------------------------------------------
c:0003 p:---- s:0007 e:000006 CFUNC  :call
c:0002 p:0035 s:0004 E:0013b0 EVAL   -e:1 [FINISH]
c:0001 p:0000 s:0002 E:001a20 TOP    [FINISH]

-- Ruby level backtrace information ----------------------------------------
-e:1:in `<main>'
-e:1:in `call'

-- Machine register context ------------------------------------------------
 rax: 0x0000000000000000 rbx: 0x0000000105d66500 rcx: 0x0000000000000000
 rdx: 0x0000000000000000 rdi: 0x0000000000000000 rsi: 0x0000000000000000
 rbp: 0x00007fff5a34de40 rsp: 0x00007fff5a34de38  r8: 0x0000000000000000
  r9: 0x0000000000000000 r10: 0x00007fff5a34dd90 r11: 0x0000000000000000
 r12: 0x0000000000000000 r13: 0x00007fba7d90c840 r14: 0x79b0ab7883740002
 r15: 0x00007fff5a34df40 rip: 0x0000000000000000 rfl: 0x0000000000010246

-- C level backtrace information -------------------------------------------
^Z
[1]+  Stopped                 RBENV_VERSION=2.2.7 ruby -rfiddle -e 'Fiddle::Function.new(Fiddle::NULL, [], Fiddle::TYPE_VOID).call'
``

[naruse (Yui NARUSE)]

• Status changed from Open to Closed

Applied in changeset trunk|r58769.

---

Treat NULL reference case [Bug #13566]

[naruse (Yui NARUSE)]

• Backport changed from 2.2: UNKNOWN, 2.3: UNKNOWN, 2.4: UNKNOWN to 2.2: REQUIRED, 2.3: REQUIRED, 2.4: REQUIRED

[mrkn (Kenta Murata)]

• Status changed from Closed to Assigned

This issue is not only for NULL but also the other address such as 0x00000000000001.

$ ruby -r fiddle -e 'Fiddle::Function.new(Fiddle::Pointer.new(1), [], Fiddle::TYPE_VOID).call'
-e:1: [BUG] Segmentation fault at 0x00000000000001
ruby 2.4.1p111 (2017-03-22 revision 58053) [x86_64-darwin16]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   for more details.
Don't forget to include the above Crash Report log file in bug reports.

-- Control frame information -----------------------------------------------
c:0003 p:---- s:0010 e:000009 CFUNC  :call
c:0002 p:0041 s:0006 e:000005 EVAL   -e:1 [FINISH]
c:0001 p:0000 s:0003 E:0006e0 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
-e:1:in `<main>'
-e:1:in `call'

-- Machine register context ------------------------------------------------
 rax: 0x0000000000000000 rbx: 0x00007fb2d7406490 rcx: 0x0000000000000000
 rdx: 0x0000000000000000 rdi: 0x0000000000000000 rsi: 0x0000000000000000
 rbp: 0x00007fff5d744ca0 rsp: 0x00007fff5d744c98  r8: 0x0000000000000000
  r9: 0x0000000000000000 r10: 0x00007fff5d744bf0 r11: 0x0000000000000001
 r12: 0x0000000000000000 r13: 0x00007fb2d88b8110 r14: 0xd9f051b4d4e700cf
 r15: 0x00007fff5d744e58 rip: 0x0000000000000001 rfl: 0x0000000000010246

-- C level backtrace information -------------------------------------------
^C^Z
[1]+  Stopped                 ruby -r fiddle -e 'Fiddle::Function.new(Fiddle::Pointer.new(1), [], Fiddle::TYPE_VOID).call'

[naruse (Yui NARUSE)]

• Status changed from Assigned to Closed

Fixed by r59710.

[hsbt (Hiroshi SHIBATA)]

• Related to Bug #13895: TestVMDump test fails on High Sierra added

[nagachika (Tomoyuki Chikanaga)]

• Backport changed from 2.2: REQUIRED, 2.3: REQUIRED, 2.4: REQUIRED to 2.2: REQUIRED, 2.3: REQUIRED, 2.4: DONE

ruby_2_4 r62639 merged revision(s) 58769,59710,59712.

[usa (Usaku NAKAMURA)]

• Backport changed from 2.2: REQUIRED, 2.3: REQUIRED, 2.4: DONE to 2.2: REQUIRED, 2.3: DONE, 2.4: DONE

ruby_2_3 r62810 merged revision(s) 58769,59710,59712.