Client#reopen not working as expected about redis_failover

[ryanlecompte]

That's interesting. It looks like the forked worker parent may also need to call #reopen on the Redis failover client. That's what the error being raised is indicating. Do you have a hook for that where you could call it?

On May 11, 2012, at 4:19 AM, Matt [email protected] wrote:

This is related to #13 but running on OSX to avoid hitting the deadlock.

I see the following stack trace when using the Client#reconnect method in my forked children (resque). I do not see the trace when I use Client#shutdown then manually recreate/reassign all the references to existing client instances. Perhaps it isn't resetting all state internally? The trace happens after my job runs, and from the trace I think it is happening in the worker parent, not the worker child nor the top level resque-pool process.

/Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/pry-exception_explorer-0.1.9/lib/pry-exception_explorer/core_ext.rb:46:in raise': You tried to use a connection inherited from another process [] You need to call reopen() after forking (Zookeeper::Exceptions::InheritedConnectionError) from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zookeeper-1.0.4/ext/zookeeper_base.rb:145:inblock in assert_open'
from /Users/mconway/.rvm/rubies/ruby-1.9.3-p125-falcon/lib/ruby/1.9.1/monitor.rb:211:in mon_synchronize' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zookeeper-1.0.4/ext/zookeeper_base.rb:141:inassert_open'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zookeeper-1.0.4/lib/zookeeper/client_methods.rb:238:in assert_open' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zookeeper-1.0.4/lib/zookeeper/client_methods.rb:16:inget'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/client/base.rb:1040:in call_and_check_rc' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/client/base.rb:437:inblock in get'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/event_handler.rb:294:in block in setup_watcher!' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/event_handler.rb:236:inblock in synchronize'
from /Users/mconway/.rvm/rubies/ruby-1.9.3-p125-falcon/lib/ruby/1.9.1/monitor.rb:211:in mon_synchronize' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/event_handler.rb:236:insynchronize'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/event_handler.rb:274:in setup_watcher!' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/client/base.rb:1087:insetup_watcher!'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/zk-1.4.0/lib/zk/client/base.rb:436:in get' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/redis_failover-040d5926f179/lib/redis_failover/client.rb:293:infetch_nodes'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/redis_failover-040d5926f179/lib/redis_failover/client.rb:273:in block in build_clients' from /Users/mconway/.rvm/rubies/ruby-1.9.3-p125-falcon/lib/ruby/1.9.1/monitor.rb:211:inmon_synchronize'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/redis_failover-040d5926f179/lib/redis_failover/client.rb:271:in build_clients' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/redis_failover-040d5926f179/lib/redis_failover/client.rb:215:indispatch'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/redis_failover-040d5926f179/lib/redis_failover/client.rb:82:in block (2 levels) in <class:Client>' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/redis-namespace-1.0.3/lib/redis/namespace.rb:213:inmethod_missing'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-fcaf987d0724/lib/resque/worker.rb:430:in job' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-fcaf987d0724/lib/resque/worker.rb:362:inunregister_worker'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-fcaf987d0724/lib/resque/worker.rb:145:in ensure in work' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-fcaf987d0724/lib/resque/worker.rb:145:inwork'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:332:in block in spawn_worker!' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:327:infork'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:327:in spawn_worker!' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:287:inblock in spawn_missing_workers_for'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:287:in times' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:287:inspawn_missing_workers_for'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:273:in block in maintain_worker_count' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:271:ineach'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:271:in maintain_worker_count' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:191:instart'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool.rb:65:in run' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool/tasks.rb:17:inblock (2 levels) in <top (required)>'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:205:in call' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:205:inblock in execute'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:200:in each' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:200:inexecute'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:158:in block in invoke_with_call_chain' from /Users/mconway/.rvm/rubies/ruby-1.9.3-p125-falcon/lib/ruby/1.9.1/monitor.rb:211:inmon_synchronize'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:151:in invoke_with_call_chain' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/gems/rake-0.9.2.2/lib/rake/task.rb:144:ininvoke'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool/cli.rb:110:in start_pool' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/lib/resque/pool/cli.rb:16:inrun'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bundler/gems/resque-pool-774e1e384d5c/bin/resque-pool:5:in <top (required)>' from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bin/resque-pool:19:inload'
from /Users/mconway/.rvm/gems/ruby-1.9.3-p125-falcon/bin/resque-pool:19:in `

'

---

Reply to this email directly or view it on GitHub:
#15

[wr0ngway]

Given that all else stays the same, and I just switch shutdown+new for reopen, it should behave the same because that was the intended behavior of reopen, no?
I have code like this:

Resque::Pool.after_prefork do |job|

  # Reset redis failover clients in worker parent so that they
  # don't conflict (deadlock) with the ones in resque-pool daemon
  RedisFactory.reconnect

  redis_factory_chained_after_fork_hook = Resque.after_fork
  Resque.after_fork do |job|

    # Reset redis failover clients in worker child so that they
    # don't conflict (deadlock) with the ones in worker parent
    RedisFactory.reconnect

    redis_factory_chained_after_fork_hook.call(job) if redis_factory_chained_after_fork_hook
  end

end

and I switch out the RedisFactory.reconnect to have one of two behaviors:

def self.reconnect
  logger.debug "RedisFactory.reconnect start"
  synchronize do
    @@clients.each do |name, client|
      client.reopen if client.respond_to?(:reopen)
    end
    @@clients.clear
  end
  logger.debug "RedisFactory.reconnect complete"    
end

or

def self.reconnect
  logger.debug "RedisFactory.reconnect start"    
  # Disconnect all redis clients (specifically for RedisFailover)
  self.shutdown

  # Reconnect resque's redis
  Resque.redis = RedisFactory.connect(:resque)

  # Reconnect Rails.cache redis
  Rails.application.config.cache_store = RedisCacheStore.new(RedisFactory.connect(:cache))
  silence_warnings { Object.const_set "RAILS_CACHE", ActiveSupport::Cache.lookup_store(Rails.application.config.cache_store) }
  logger.debug "RedisFactory.reconnect complete"    
end

def self.shutdown
  logger.debug "RedisFactory.shutdown start"
  synchronize do
    @@clients.each do |name, client|
      client.shutdown if client.respond_to?(:shutdown)
    end
    @@clients.clear
  end
  logger.debug "RedisFactory.shutdown complete"    
end

[ryanlecompte]

Actually yes, I think I see the issue. Instead of closing down the ZK client and recreating it, I should just need to call #reopen on it. It's 4:42AM here so I will try this in a few hours. If you'd like to experiment, though you could fork the project and change #reopen in client.rb to be this:

def reopen
purge_clients
@zk.reopen if @zk
build_clients
end

On May 11, 2012, at 4:31 AM, Matt [email protected] wrote:

Given that all else stays the same, and I just switch shutdown+new for reopen, it should behave the same because that was the intended behavior of reopen, no?
I have code like this:

Resque::Pool.after_prefork do |job|

 # Reset redis failover clients in worker parent so that they
 # don't conflict (deadlock) with the ones in resque-pool daemon
 RedisFactory.reconnect

 redis_factory_chained_after_fork_hook = Resque.after_fork
 Resque.after_fork do |job|

   # Reset redis failover clients in worker child so that they
   # don't conflict (deadlock) with the ones in worker parent
   RedisFactory.reconnect

   redis_factory_chained_after_fork_hook.call(job) if redis_factory_chained_after_fork_hook
 end

end

and I switch out the RedisFactory.reconnect to have one of two behaviors:

def self.reconnect
logger.debug "RedisFactory.reconnect start"
synchronize do
@@clients.each do |name, client|
client.reopen if client.respond_to?(:reopen)
end
@@clients.clear
end
logger.debug "RedisFactory.reconnect complete"
end

or

def self.reconnect
logger.debug "RedisFactory.reconnect start"
# Disconnect all redis clients (specifically for RedisFailover)
self.shutdown

 # Reconnect resque's redis
 Resque.redis = RedisFactory.connect(:resque)

 # Reconnect Rails.cache redis
 Rails.application.config.cache_store = RedisCacheStore.new(RedisFactory.connect(:cache))
 silence_warnings { Object.const_set "RAILS_CACHE", ActiveSupport::Cache.lookup_store(Rails.application.config.cache_store) }
 logger.debug "RedisFactory.reconnect complete"    

end

def self.shutdown
logger.debug "RedisFactory.shutdown start"
synchronize do
@@clients.each do |name, client|
client.shutdown if client.respond_to?(:shutdown)
end
@@clients.clear
end
logger.debug "RedisFactory.shutdown complete"
end

---

Reply to this email directly or view it on GitHub:
#15 (comment)

[wr0ngway]

No worries, go to sleep :)
For when you wake up, the alternate reopen exhibited the same problem

[ryanlecompte]

Hey @slyphon, this could be related to what you are currently fixing in ZK, right?

On May 11, 2012, at 5:03 AM, Matt [email protected] wrote:

No worries, go to sleep :)
For when you wake up, the alternate reopen exhibited the same problem

---

Reply to this email directly or view it on GitHub:
#15 (comment)

[slyphon]

It might be, but if this is truly happening in the parent, then that's a bug in zookeeper, but i'm a little skeptical that's where it's getting triggered. It seems like this might be getting triggered from the paranoid "check the node every N seconds loop"?

Anyway, check the pull request, that's how i would respond to this exception.

[ryanlecompte]

Okay, I just merged @slyphon's pull request and changed the code to use #reopen. @wr0ngway, can you give this a shot? Thanks!

[ryanlecompte]

Fixed