Project

General

Profile

Actions

Bug #17382

closed

Segfault in String#inspect

Added by lionelperrin (Lionel Perrin) over 1 year ago. Updated 5 months ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
-
ruby -v:
ruby 2.7.2p137 (2020-10-01 revision 5445e04352) [x86_64-linux]
[ruby-core:101343]

Description

Hello,

We experienced a segfault in our application. It seems that it happened right after we've upgraded from ruby 2.6 to ruby 2.7.2.
The faulting ruby code is actionpack-6.0.3.4/lib/action_controller/log_subscriber.rb:16:

info "  Parameters: #{params.inspect}" unless params.empty?

However, the problem seems to be due to string.c:10702

Here is an extract of the output from ruby (full output attached):

-- Control frame information -----------------------------------------------
c:0073 p:---- s:0500 e:000499 CFUNC  :inspect
c:0072 p:---- s:0497 e:000496 CFUNC  :inspect
c:0071 p:0137 s:0493 e:000490 METHOD /usr/app/rubygems/ruby/2.7.0/gems/actionpack-6.0.3.4/lib/action_controller/log_subscriber.rb:16
c:0070 p:0038 s:0483 e:000482 METHOD /usr/app/rubygems/ruby/2.7.0/gems/activesupport-6.0.3.4/lib/active_support/subscriber.rb:145
...
-- Ruby level backtrace information ----------------------------------------
/usr/app/rubygems/ruby/2.7.0/gems/puma-5.0.4/lib/puma/thread_pool.rb:145:in `block in spawn_thread'
/usr/app/rubygems/ruby/2.7.0/gems/puma-5.0.4/lib/puma/server.rb:430:in `process_client'
/usr/app/rubygems/ruby/2.7.0/gems/puma-5.0.4/lib/puma/request.rb:75:in `handle_request'
...
-- Machine register context ------------------------------------------------
 RIP: 0x00007fd7ab8b0f5c RBP: 0x00007fd7844b92c8 RSP: 0x00007fd7a4af7fe0
 RAX: 0x00005597fb1672c0 RBX: 0x0000000000000000 RCX: 0x00007fd7ab8b1060
 RDX: 0x0000000000000000 RDI: 0x0000000000000000 RSI: 0x0000000000000000
  R8: 0x00007fd7a4bf8d50  R9: 0x00005597ffce6378 R10: 0x0000000055550083
 R11: 0x0000000000000000 R12: 0x0000000000000000 R13: 0x00005597fb1b0038
 R14: 0x00005597fb1672c0 R15: 0x0000000000000000 EFL: 0x0000000000010206
-- C level backtrace information -------------------------------------------
/usr/local/lib/libruby.so.2.7(rb_vm_bugreport+0x555) [0x7fd7ab9176f5] vm_dump.c:755
[0x7fd7ab756427]
/usr/local/lib/libruby.so.2.7(sigsegv+0x4b) [0x7fd7ab88311b] signal.c:946
/lib/x86_64-linux-gnu/libpthread.so.0(__restore_rt+0x0) [0x7fd7ab45f730]
/usr/local/lib/libruby.so.2.7(rb_str_symname_p+0x1c) [0x7fd7ab8b0f5c] string.c:10702
/usr/local/lib/libruby.so.2.7(sym_inspect+0x1a) [0x7fd7ab8b107a] string.c:10761
[0x7fd7ab909271]
/usr/local/lib/libruby.so.2.7(rb_funcallv_with_cc+0x118) [0x7fd7ab90bb68] vm_eval.c:1013

Files

ruby_segfault_log.txt (86.2 KB) ruby_segfault_log.txt lionelperrin (Lionel Perrin), 12/09/2020 03:32 PM
segfault.rb (1.03 KB) segfault.rb Script to reproduce segfault tom_dalling (Tom Dalling), 02/25/2022 06:24 AM
log.txt (40.3 KB) log.txt tom_dalling (Tom Dalling), 02/25/2022 06:33 AM
repro.zip (17.5 KB) repro.zip tom_dalling (Tom Dalling), 02/25/2022 10:39 AM

Related issues 2 (1 open1 closed)

Related to Ruby master - Bug #17289: Time#strftime occurs Segmentation Fault on ruby-2.7.2p137Assignedshyouhei (Shyouhei Urabe)Actions
Related to Ruby master - Bug #17362: Thread core dumpClosedActions

Updated by mame (Yusuke Endoh) over 1 year ago

Thank you for the report. I think that this is the same issue as #17289 and #17362. Unfortunately, the core team has no reproducible code, so we haven't investigated the issue yet. Can you provide your code, or at least, the core dump file?

Actions #2

Updated by mame (Yusuke Endoh) over 1 year ago

  • Related to Bug #17289: Time#strftime occurs Segmentation Fault on ruby-2.7.2p137 added
Actions #3

Updated by mame (Yusuke Endoh) over 1 year ago

Actions #4

Updated by jeremyevans0 (Jeremy Evans) 10 months ago

  • Status changed from Open to Closed

Updated by tom_dalling (Tom Dalling) 6 months ago

I've attached code that reproduces the issue, along with output and the macOS crash report from my machine. Just run bundle and then ruby segfault.rb. It reliably segfaults for me within a minute or two on Ruby 2.7.5. I tried it on Ruby 3.1.1, and it doesn't appear to have the same problem.

We started seeing this segfault after upgrading to Ruby 2.7, and continue to see it almost daily in production.

It seems that both rails and anyway_config need to be required to trigger the issue. I'm not sure why, but if I had to guess I would say that it's something related to either refinements or pattern matching.

With this new information, could we reopen the issue please?

Actions #8

Updated by mame (Yusuke Endoh) 6 months ago

  • Status changed from Closed to Open

Updated by palkan (Vladimir Dementyev) 6 months ago

I was able to reduce the reproduction example (and excluded anyway_config from the equation, kind of).

I guess, there is something with the following refinement (extracted from anyway_config):

module UsingRefinements
  using(Module.new do
    refine Hash do
      def inspect
        "{#{map { |k, v| "#{k}: #{v.inspect}" }.join(", ")}}"
      end
    end
  end)
end

And the Rails core extensions.

Here is the diff of the segfault.rb which reproduces the problem (assuming the refinement above is located in the using_refinements.rb next to the segfault.rb):

- Bundler.require
+ require "active_support/core_ext/object/json"
+ require_relative 'using_refinements'

Updated by wanabe (_ wanabe) 5 months ago

I shortened the reproduction code.

Array.prepend(Module.new)

module UsingRefinements
  using(Module.new do
    refine Array do
      def inspect
        each { |v| v.inspect }
        ""
      end
    end
  end)
end

h = [[:foo] * 8] * 8
20.times.map { Thread.new { 10_000.times { |i| h.inspect } } }.map(&:join)
p :done
$ ./miniruby -v segfault.rb 
ruby 2.7.6p209 (2021-12-31 revision 1034b6e7ba) [x86_64-linux]
segfault.rb:15: [BUG] Segmentation fault at 0x0000000000000000
(snip)

There are search results for git bisect.

  • f2286925f08406bc857f7b03ad6779a5d61443ae will fix the issue but it is too large to backport.
  • 66c644da5e80258bb3217941223d923f923c3548 is the first commit that creates a problem at least as far as I have observed.

And I have confirmed that the problem is suppressed by the revert commit.

diff --git a/vm_eval.c b/vm_eval.c
index 76e56fac8a..3ef6ff3cd9 100644
--- a/vm_eval.c
+++ b/vm_eval.c
@@ -1010,17 +1010,7 @@ rb_funcallv_with_cc(struct rb_call_data *cd, VALUE recv, ID mid, int argc, const
         vm_search_method(cd, recv);
 
         if (LIKELY(! UNDEFINED_METHOD_ENTRY_P(cc->me))) {
-            return vm_call0_body(
-                GET_EC(),
-                &(struct rb_calling_info) {
-                    Qundef,
-                    recv,
-                    argc,
-                    RB_NO_KEYWORDS,
-                },
-                cd,
-                argv
-            );
+            return rb_vm_call0(GET_EC(), recv, mid, argc, argv, cc->me, RB_NO_KEYWORDS);
         }
     }

However, this is not a backport and I am not sure if it is acceptable from a policy standpoint.

Updated by wanabe (_ wanabe) 5 months ago

Alternatively, the following seems to solve the problem.

diff --git a/vm_eval.c b/vm_eval.c
index 76e56fac8a..64af8815ea 100644
--- a/vm_eval.c
+++ b/vm_eval.c
@@ -1018,7 +1018,7 @@ rb_funcallv_with_cc(struct rb_call_data *cd, VALUE recv, ID mid, int argc, const
                     argc,
                     RB_NO_KEYWORDS,
                 },
-                cd,
+                &(struct rb_call_data) { *cc, *ci },
                 argv
             );
         }

Updated by shyouhei (Shyouhei Urabe) 5 months ago

@palkan (Vladimir Dementyev) thank you for the reproducer. That hepls us a lot.

Also thank you @wanabe (_ wanabe). I'm :+1: for the "alternative" approach in #note-11.

Updated by wanabe (_ wanabe) 5 months ago

  • Status changed from Open to Closed

Thank you for confirming.
This is not reproduced in 3.0 or later, and it would be better to close this issue, leaving the decision to the backport maintainer.
I'm going to close it.

Actions

Also available in: Atom PDF