resque / redis-namespace

This gem adds a Redis::Namespace class which can be used to namespace Redis keys.
http://redis.io
MIT License
695 stars 192 forks source link

ERR MULTI calls can not be nested after upgrade to redis 4.6.0 #191

Closed ArturT closed 2 years ago

ArturT commented 2 years ago

I use redis-namespace 1.8.1. I upgraded redis gem from 4.5.1 to 4.6.0 and I noticed errors from time to time in our Sidekiq workers.

Redis::CommandError: ERR MULTI calls can not be nested

I believe this is related to recent changes in redis gem regarding multi method: https://github.com/redis/redis-rb/blob/master/CHANGELOG.md#460

Deprecate calling commands on Redis inside Redis#multi.

redis.multi do
  redis.get("key")
end

should be replaced by:

redis.multi do |transaction|
  transaction.get("key")
end

Here is how to reproduce the error.

# reproduce_bug.rb
require 'redis'
require 'redis-namespace'
key = 'a_key'
threads = []
redis = Redis.new(timeout: 5)
redis = Redis::Namespace.new('my-namespace', redis: redis)
1000.times do
  threads << Thread.new do
    redis.multi do |transaction|
      transaction.incr(key)
      transaction.expire(key, 360)
    end
  end
end

threads.each(&:join)
puts 'it works!'

Then run in bash this

while [ "$?" == 0 ]; do ruby reproduce_bug.rb; done

It will keep running the script until it fails.

bash-3.2$ while [ "$?" == 0 ]; do ruby reproduce_bug.rb; done
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
it works!
#<Thread:0x0000000155952da0 reproduce_bug.rb:8 run> terminated with exception (report_on_exception is true):
/Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:246:in `call_pipelined': ERR MULTI calls can not be nested (Redis::CommandError)
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:200:in `block in call_pipeline'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:344:in `with_reconnect'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:198:in `call_pipeline'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:221:in `block in multi'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `block in synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:215:in `multi'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-namespace-1.8.1/lib/redis/namespace.rb:523:in `namespaced_block'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-namespace-1.8.1/lib/redis/namespace.rb:294:in `multi'
    from reproduce_bug.rb:9:in `block (2 levels) in <main>'
/Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:246:in `call_pipelined': ERR MULTI calls can not be nested (Redis::CommandError)
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:200:in `block in call_pipeline'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:344:in `with_reconnect'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis/client.rb:198:in `call_pipeline'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:221:in `block in multi'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `block in synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:258:in `synchronize'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-4.6.0/lib/redis.rb:215:in `multi'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-namespace-1.8.1/lib/redis/namespace.rb:523:in `namespaced_block'
    from /Users/artur/.rvm/gems/ruby-3.0.3/gems/redis-namespace-1.8.1/lib/redis/namespace.rb:294:in `multi'
    from reproduce_bug.rb:9:in `block (2 levels) in <main>'

Here the line in redis-namespace. Maybe it somehow wrongly use redis gem after the latest changes for multi ( https://github.com/redis/redis-rb/pull/1059 )?

related issue in redis gem repo

I reported the issue also in redis gem https://github.com/redis/redis-rb/issues/1069#issuecomment-1059191436 but we found out that it happens only when using redis-namespace gem.

ArturT commented 2 years ago

Here is a script that can help pinpoint the issue. https://github.com/redis/redis-rb/issues/1069#issuecomment-1060382359

Maybe something is wrong with the following code when running in threads and @redis is overridden.

https://github.com/resque/redis-namespace/blob/7e43f2d1e64747955f9e6dd0ded9e37661bd7100/lib/redis/namespace.rb#L525

ArturT commented 2 years ago

The issue has been solved by this PR: https://github.com/resque/redis-namespace/pull/192