Segfault when getting thread-local variable #2566

kddnewton · 2021-03-08T14:58:05Z

tl;dr: segfault, puma 5.2.2, ruby 2.6.6p146, 2 workers in cluster mode, lib/puma/cluster.rb:337.

Describe the bug

I got a dependabot PR to update my app to the latest puma. When I try to boot the app, I'm getting a segfault. Here's the backtrace:

Backtrace

=> Booting Puma
=> Rails 6.0.3.4 application starting in development 
=> Run `rails server --help` for more startup options
[77985] Puma starting in cluster mode...
[77985] * Puma version: 5.2.2 (ruby 2.6.6-p146) ("Fettisdagsbulle")
[77985] *  Min threads: 5
[77985] *  Max threads: 5
[77985] *  Environment: development
[77985] *   Master PID: 77985
[77985] *      Workers: 2
/Users/kddeisz/.gem/ruby/2.6.6/gems/puma-5.2.2/lib/puma/cluster.rb:337: [BUG] Segmentation fault at 0x0000000000000008
ruby 2.6.6p146 (2020-03-31 revision 67876) [x86_64-darwin19]

-- 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:0036 p:---- s:0229 e:000228 CFUNC  :thread_variable_get
c:0035 p:0008 s:0224 e:000223 BLOCK  /Users/kddeisz/.gem/ruby/2.6.6/gems/puma-5.2.2/lib/puma/cluster.rb:337 [FINISH]
c:0034 p:---- s:0220 e:000219 CFUNC  :reject
c:0033 p:0055 s:0216 e:000215 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/puma-5.2.2/lib/puma/cluster.rb:337
c:0032 p:0124 s:0201 e:000200 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/puma-5.2.2/lib/puma/launcher.rb:181
c:0031 p:0090 s:0194 E:0006a8 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/puma-5.2.2/lib/rack/handler/puma.rb:72
c:0030 p:0229 s:0185 E:0001e0 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/rack-2.2.3/lib/rack/server.rb:327
c:0029 p:0043 s:0179 E:000868 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/commands/server/server_command.rb:39
c:0028 p:0074 s:0174 E:000720 BLOCK  /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/commands/server/server_command.rb:147 [FINISH]
c:0027 p:---- s:0169 e:000168 CFUNC  :tap
c:0026 p:0035 s:0165 E:0003c0 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/commands/server/server_command.rb:138
c:0025 p:0064 s:0161 E:000460 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/thor-1.1.0/lib/thor/command.rb:27
c:0024 p:0047 s:0153 E:000498 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/thor-1.1.0/lib/thor/invocation.rb:127
c:0023 p:0259 s:0146 E:000508 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/thor-1.1.0/lib/thor.rb:392
c:0022 p:0043 s:0133 E:000548 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/command/base.rb:69
c:0021 p:0130 s:0126 E:0005a8 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/command.rb:46
c:0020 p:0059 s:0115 E:0005e0 TOP    /Users/kddeisz/.gem/ruby/2.6.6/gems/railties-6.0.3.4/lib/rails/commands.rb:18 [FINISH]
c:0019 p:---- s:0110 e:000109 CFUNC  :require
c:0018 p:0013 s:0105 E:000630 BLOCK  /Users/kddeisz/.gem/ruby/2.6.6/gems/bootsnap-1.7.2/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23
c:0017 p:0074 s:0102 E:0006c0 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/bootsnap-1.7.2/lib/bootsnap/load_path_cache/loaded_features_index.rb:92
c:0016 p:0023 s:0090 E:000610 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/bootsnap-1.7.2/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22
c:0015 p:0063 s:0084 E:000700 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/bootsnap-1.7.2/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31
c:0014 p:0051 s:0076 E:000728 TOP    /Users/kddeisz/src/github.com/Shopify/.../bin/rails:9 [FINISH]
c:0013 p:---- s:0072 e:000071 CFUNC  :load
c:0012 p:0135 s:0067 E:000758 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/spring-2.1.1/lib/spring/client/rails.rb:28
c:0011 p:0009 s:0062 E:000788 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/spring-2.1.1/lib/spring/client/command.rb:7
c:0010 p:0014 s:0057 E:0007c0 METHOD /Users/kddeisz/.gem/ruby/2.6.6/gems/spring-2.1.1/lib/spring/client.rb:30
c:0009 p:0295 s:0051 E:0007f8 TOP    /Users/kddeisz/.gem/ruby/2.6.6/gems/spring-2.1.1/bin/spring:49 [FINISH]
c:0008 p:---- s:0045 e:000044 CFUNC  :load
c:0007 p:0115 s:0040 E:000838 TOP    /Users/kddeisz/.gem/ruby/2.6.6/gems/spring-2.1.1/lib/spring/binstub.rb:11 [FINISH]
c:0006 p:---- s:0034 e:000033 CFUNC  :require
c:0005 p:0110 s:0029 E:0008a0 METHOD /opt/rubies/2.6.6/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54
c:0004 p:0129 s:0017 E:0008d0 TOP    /Users/kddeisz/src/github.com/Shopify/.../bin/spring:14 [FINISH]
c:0003 p:---- s:0012 e:000011 CFUNC  :load
c:0002 p:0018 s:0007 E:000888 EVAL   /Users/kddeisz/src/github.com/Shopify/.../bin/rails:3 [FINISH]
c:0001 p:0000 s:0003 E:001260 (none) [FINISH]

Puma config:

Here's my config/puma.rb:

puma.rb

workers(Rails.application.config.concurrency.workers)
threads_count = Rails.application.config.concurrency.threads
threads(threads_count, threads_count)

preload_app!

rackup(DefaultRackup)
port(ENV['PORT'] || 3000)
environment(ENV['RACK_ENV'] || 'development')

on_worker_boot do
  ActiveRecord::Base.establish_connection
end

if Rails.env.development?
  worker_timeout(5 * 60)
end

To Reproduce

I'll keep working on reproduction steps and digging into it, but I figured I'd get the bug in first in case it was an obvious/easy fix.

Desktop (please complete the following information):

OS: [e.g. Mac, Linux] Darwin 19.6.0; root:xnu-6153.141.2~1/RELEASE_X86_64 x86_64
Puma Version [e.g. 4.1.1] 5.2.2

The text was updated successfully, but these errors were encountered:

kddnewton · 2021-03-08T15:05:59Z

Update: after git bisecting puma, it looks like the issue is with this commit: b6ca443.

MSP-Greg · 2021-03-08T15:16:48Z

@kddeisz

I need to look at it more and check the test suite, but the fix might be changing the two instances of the following in cluster.rb:

Thread.list.reject { |t| t.thread_variable_get(:fork_safe) }

to

Thread.list.reject { |t| t.thread_variable?(:fork_safe) && t.thread_variable_get(:fork_safe) }

Once the app preloads, there may be threads without the variable.

Regardless, Ruby shouldn't be SEGV'ing...

kddnewton · 2021-03-08T15:19:58Z

@MSP-Greg unfortunately that didn't fix it.

It looks like it's a specific thread though every time, it's always Process::Waiter. I have no idea what this is though.

kddnewton · 2021-03-08T15:25:08Z

Okay, @MSP-Greg for some reason this fixes it:

diff --git a/lib/puma/cluster.rb b/lib/puma/cluster.rb
index c2eff7da..c7247022 100644
--- a/lib/puma/cluster.rb
+++ b/lib/puma/cluster.rb
@@ -333,13 +333,13 @@ module Puma
 
       # Threads explicitly marked as fork safe will be ignored.
       # Used in Rails, but may be used by anyone.
-      before = Thread.list.reject { |t| t.thread_variable_get(:fork_safe) }
+      before = Thread.list.reject { |t| !t.is_a?(Process::Waiter) && t.thread_variable_get(:fork_safe) }
 
       if preload?
         log "* Preloading application"
         load_and_bind
 
-        after = Thread.list.reject { |t| t.thread_variable_get(:fork_safe) }
+        after = Thread.list.reject { |t| !t.is_a?(Process::Waiter) && t.thread_variable_get(:fork_safe) }
 
         if after.size > before.size
           threads = (after - before)

kddnewton · 2021-03-08T15:30:44Z

Yeah this segfaults in 2.6.6, but works in 2.7.1:

if pid = fork
  Process.detach(pid)
  puts "PARENT!!! #{Thread.list.map { |t| t.thread_variable_get(:foo) }}"
else
  puts "CHILD!!!"
end

kddnewton · 2021-03-08T15:44:58Z

I think maybe ruby/ruby@cadfaac#diff-161b2a279f4c67a1ab075a7890ecf6f3f1d483d910910fa52b3715e25cfdcbd7 fixed this?

MSP-Greg · 2021-03-08T16:06:59Z

Process::Waiter - https://msp-greg.github.io/ruby_2_2/Core/Process/Waiter.html

See https://bugs.ruby-lang.org/issues/10231.

Sorry, I'm intermittently AFK

When you're trying to access a thread-local variable on Ruby < 2.7, and you call `thread_variable_get` on a `Process::Waiter` (a subclass of `Thread`), it will segfault. This adds a check for which Ruby version you're on to make it safe for Ruby 2.6. Fixes #2566.

When you're trying to access a thread-local variable on Ruby < 2.7, and you call `thread_variable_get` on a `Process::Waiter` (a subclass of `Thread`), it will segfault. This adds a check for which Ruby version you're on to make it safe for Ruby 2.6. Fixes puma#2566.

kddnewton mentioned this issue Mar 8, 2021

Handle segfault in Ruby 2.6.6 on thread-locals #2567

Merged

8 tasks

nateberkopec closed this as completed in #2567 Apr 19, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Segfault when getting thread-local variable #2566

Segfault when getting thread-local variable #2566

kddnewton commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021

MSP-Greg commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021

kddnewton commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021

MSP-Greg commented Mar 8, 2021 •

edited

Segfault when getting thread-local variable #2566

Segfault when getting thread-local variable #2566

Comments

kddnewton commented Mar 8, 2021 • edited

kddnewton commented Mar 8, 2021

MSP-Greg commented Mar 8, 2021 • edited

kddnewton commented Mar 8, 2021

kddnewton commented Mar 8, 2021 • edited

kddnewton commented Mar 8, 2021 • edited

kddnewton commented Mar 8, 2021

MSP-Greg commented Mar 8, 2021 • edited

kddnewton commented Mar 8, 2021 •

edited

MSP-Greg commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021 •

edited

kddnewton commented Mar 8, 2021 •

edited

MSP-Greg commented Mar 8, 2021 •

edited