Rails app freeze in deadlock

[nateless]

Spent whole day trying to figure out what's happening. We use Redis and initialize it at load in initialize file with global variable $redis. In controller we have something like this:

class StreamController < ApplicationController
    include Tubesock::Hijack

    respond_to :json

    def index
        hijack do |tubesock|
            tubesock.onopen do
                StreamService.add(current_user, tubesock)

                $redis.publish('online', {params: online}.to_json)
            end

            tubesock.onmessage do |data|
                #...
            end

            tubesock.onclose do
                $redis.publish('online', {params: online}.to_json)
            end
        end
    end

    private
    def online
        StreamService.size
    end
end

At random time app freeze, strace shows:

futex(0x7fc845d826a4, FUTEX_WAIT_PRIVATE, 1, NULL

I've added another thread at rails initialization which just dumps Threads.list with backtrace for each of them each second, after some load (just open a lot of connections to site) app freeze and this is what I have [I've removed irrelevant threads]:

I, [2015-02-11T20:23:01.618508 #6876]  INFO -- : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
I, [2015-02-11T20:23:01.618533 #6876]  INFO -- : #<Thread:0x007f42108f3640>
I, [2015-02-11T20:23:01.620581 #6876]  INFO -- : #<Thread:0x007f421158ce60>
I, [2015-02-11T20:23:01.622522 #6876]  INFO -- : #<Thread:0x007f42112f5df0>
I, [2015-02-11T20:23:01.620616 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:185:in `lock'
I, [2015-02-11T20:23:01.620641 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:185:in `mon_enter'
I, [2015-02-11T20:23:01.620663 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:209:in `mon_synchronize'
I, [2015-02-11T20:23:01.620683 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/gems/redis-3.2.0/lib/redis.rb:37:in `synchronize'
I, [2015-02-11T20:23:01.620702 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/gems/redis-3.2.0/lib/redis.rb:1994:in `publish'
I, [2015-02-11T20:23:01.620722 #6876]  INFO -- : /home/ubuntu/test/releases/20150211154256/app/controllers/stream_controller.rb:45:in `block (2 levels) in index'
I, [2015-02-11T20:23:01.620742 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:62:in `call'
I, [2015-02-11T20:23:01.620762 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:62:in `each'
I, [2015-02-11T20:23:01.620790 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:62:in `block in listen'
I, [2015-02-11T20:23:01.620839 #6876]  INFO -- : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
I, [2015-02-11T20:23:01.622768 #6876]  INFO -- : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
I, [2015-02-11T20:23:01.622787 #6876]  INFO -- : #<Thread:0x007f42112f77e0>
I, [2015-02-11T20:23:01.622827 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:185:in `lock'
I, [2015-02-11T20:23:01.622853 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:185:in `mon_enter'
I, [2015-02-11T20:23:01.622876 #6876]  INFO -- : /home/ubuntu/.rbenv/versions/2.2.0/lib/ruby/2.2.0/monitor.rb:209:in `mon_synchronize'
I, [2015-02-11T20:23:01.622933 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/gems/redis-3.2.0/lib/redis.rb:37:in `synchronize'
I, [2015-02-11T20:23:01.622957 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/gems/redis-3.2.0/lib/redis.rb:1994:in `publish'
I, [2015-02-11T20:23:01.622977 #6876]  INFO -- : /home/ubuntu/test/releases/20150211154256/app/controllers/stream_controller.rb:84:in `block (2 levels) in index'
I, [2015-02-11T20:23:01.623007 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:71:in `call'
I, [2015-02-11T20:23:01.623030 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:71:in `each'
I, [2015-02-11T20:23:01.623050 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:71:in `close'
I, [2015-02-11T20:23:01.623070 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:43:in `rescue in send_data'
I, [2015-02-11T20:23:01.623090 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:36:in `send_data'
I, [2015-02-11T20:23:01.623110 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:88:in `block (2 levels) in keepalive'
I, [2015-02-11T20:23:01.623131 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:86:in `loop'
I, [2015-02-11T20:23:01.623151 #6876]  INFO -- : /home/ubuntu/test/shared/bundle/ruby/2.2.0/bundler/gems/tubesock-f74c2bceb86a/lib/tubesock.rb:86:in `block in keepalive'
I, [2015-02-11T20:23:01.623172 #6876]  INFO -- : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

First backtraces stream_controller.rb:45 refers to our line $redis.publish in onopen callback and second regarding $redis.publish in onclose.

I've tried to change onopen and onclose callbacks to this version:

            tubesock.onopen do
                StreamService.add(current_user, tubesock)

                redis = Redis.new(:driver => :hiredis)
                redis.publish('online', {params: online}.to_json)
            end

And at the moment it works fine, however the question is why it stuck in deadlock using global var?

[ngauthier]

My guess is simply that the ruby library for redis is not threadsafe (after opening the connection). But I'm not sure.

While reading this thread I was going to recommend Redis.new inside the handlers, but you had figured it out.