Issue #14634 has been updated by zetaben (Benoit Larroque).

File rev62852.txt added

Hello Eric,

I just tried compiling & running with r62852 on my computer. I still have the same issue:
~~~
/versatile/queue2.rb:62: [BUG] pthread_mutex_lock: Invalid argument (EINVAL)    
ruby 2.5.0p43 (2018-03-19 revision 62852) [x86_64-linux]                        
                                                                                
-- Control frame information -----------------------------------------------    
c:0003 p:---- s:0014 e:000013 CFUNC  :push 
~~~
(please find full trace attached)

Looking a bit through the issues earlier, I actually found that https://bugs.ruby-lang.org/issues/14474 was having very similar symptoms as my issue but the offending test seemed not really related (threads only no queue). I forgot to mention this in my initial report, sorry!

----------------------------------------
Bug #14634: Queue#push seems to crash after fork
https://bugs.ruby-lang.org/issues/14634#change-71242

* Author: zetaben (Benoit Larroque)
* Status: Open
* Priority: Normal
* Assignee: 
* Target version: 
* ruby -v: ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux]
* Backport: 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: UNKNOWN
----------------------------------------
Hello, 

We are providing an [agent that uses dynamic instrumentation](https://blog.sqreen.io/dynamic-instrumentation-agent-for-ruby/) to provide additional security checks on Rails applications.

We recently received issues from one of our customers that just upgraded from Ruby 2.4 to 2.5.0 on Heroku about segfault coming from inside the gem. These seemed to happen randomly when our agent was pushing to a Ruby Queue (that is consumed by our reporting thread).

We managed to reproduced this issue locally using the customer application code. It seems to happen regularly to the first Queue#push done by the instrumented Unicorn worker just after startup:
- Master start-up
- Our agent starts, connects to our backend, apply instrumentation, creates the queue and starts listening on it (Queue#pop interrupted by a Timeout in an infinite loop)
- Master fork and launch worker
- Worker starts to answer HTTP traffic
- Agent detects that reporting thread is dead (because of fork) and restarts a thread listening on the same Queue instance but in the new process
- Worker handles another HTTP request and tries to Queue#push some metrics to Queue instance

==> Ruby then crashes with either:
- Most often: `[BUG] pthread_mutex_lock: Invalid argument (EINVAL)`
- Sometime with `[BUG] Segmentation fault at 0x0000000000000038`

Both being located to:
~~~
c:0052 p:---- s:0384 e:000383 CFUNC  :push
~~~
which would be the C-func that pushes in the Queue.

I'm attaching the stripped bug report traces to ticket.

We found a workaround by actually recreating a new Queue instance on agent start in the worker (So it does not happen on a brand new Queue after forking).

Also, the first workaround we tried though was copying the pure Ruby Queue implementation from previous Ruby versions (circa 2.0.0). This actually didn't work and lead to a similar crash happening this time on the ConditionVariable

~~~
2018-03-21T22:53:41.973451+00:00 app[web.2]: /app/vendor/bundle/ruby/2.5.0/gems/sqreen-1.11.2/lib/sqreen/backported_queue.rb:24: [BUG] pthread_mutex_lock: Invalid argument (EINVAL)
2018-03-21T22:53:41.973454+00:00 app[web.2]: ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux]
2018-03-21T22:53:41.973456+00:00 app[web.2]:
2018-03-21T22:53:41.973457+00:00 app[web.2]: -- Control frame information -----------------------------------------------
2018-03-21T22:53:41.973462+00:00 app[web.2]: c:0057 p:---- s:0407 e:000406 CFUNC  :signal
2018-03-21T22:53:41.973466+00:00 app[web.2]: c:0056 p:0017 s:0403 e:000402 BLOCK  /app/vendor/bundle/ruby/2.5.0/gems/sqreen-1.11.2/lib/sqreen/backported_queue.rb:24 [FINISH]
2018-03-21T22:53:41.973473+00:00 app[web.2]: c:0055 p:---- s:0400 e:000399 CFUNC  :synchronize
2018-03-21T22:53:41.973481+00:00 app[web.2]: c:0054 p:0008 s:0396 e:000395 BLOCK  /app/vendor/bundle/ruby/2.5.0/gems/sqreen-1.11.2/lib/sqreen/backported_queue.rb:22 [FINISH]
2018-03-21T22:53:41.973489+00:00 app[web.2]: c:0053 p:---- s:0393 e:000392 CFUNC  :handle_interrupt
2018-03-21T22:53:41.973502+00:00 app[web.2]: c:0052 p:0022 s:0388 e:000387 METHOD /app/vendor/bundle/ruby/2.5.0/gems/sqreen-1.11.2/lib/sqreen/backported_queue.rb:21
2018-03-21T22:53:41.973507+00:00 app[web.2]: c:0051 p:0031 s:0383 e:000382 METHOD /app/vendor/bundle/ruby/2.5.0/gems/sqreen-1.11.2/lib/sqreen/capped_queue.rb:22
~~~

While putting my ideas in order when writing this bug report I finally managed to find a way to reproduce the issue in a simple Ruby script. Please find it attached with matching Ruby trace report.

Nota this script does *not* crash in the following Ruby version on my computer:
ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-linux]
ruby 2.4.3p205 (2017-12-14 revision 61247) [x86_64-linux]

but does crash under:
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux]

Let me know if I can help further

Finally, thanks for writing & maintaining such an awesome language !






---Files--------------------------------
einval.stripped.txt (59.9 KB)
sigsegv.stripped.txt (60.8 KB)
queue2.rb (1.15 KB)
repro.trace.txt (12.6 KB)
rev62852.txt (10.3 KB)


-- 
https://bugs.ruby-lang.org/

Unsubscribe: <mailto:ruby-core-request / ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>