redis-rb: New pipelining syntax (v4.6.0) causes "ERR MULTI calls can not be nested"

We have some code like the following in production (which has been working for years):

$redis.with do |conn|
  conn.pipelined do
    conn.multi do |multi|
      multi.hincrby notification_key, attribute, by
      multi.expire notification_key, 9999
    end
    conn.multi do |multi|
      multi.hincrby project_key, attribute, by
      multi.expire project_key, 9999
    end
    conn.multi do |multi|
      # etc.
    end
  end
end

Now, after upgrading the redis gem to the latest version (from 4.5.1 to 4.6.0) we get this deprecation warning:

Pipelining commands on a Redis instance is deprecated and will be removed in Redis 5.0.0.

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

should be replaced by

redis.pipelined do |pipeline|
  pipeline.get("key")
end

If we ignore the warning our tests are still passing (with warnings).

However when we update the syntax, following the instructions, all our code fails with errors:

Failure/Error:
  conn.pipelined do |pipeline|
    pipeline.multi do |multi|
      multi.hincrby notification_key, attribute, by
      multi.expire notification_key, 9999
    end
    pipeline.multi do |multi|
      multi.hincrby project_key, attribute, by
      multi.expire project_key, 9999
    end

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

Is it a bug in the new version of this gem? Otherwise, what should we do?

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 30

Commits related to this issue

Most upvoted comments

Ok, took me a while, but I figured it out. Trying to braindump the issue before I work on a solution.

  • Redis::Namespace rely on the Redis instance synchonization.
  • It worked until now because multi would yield self, so Namespace @redis would always synchronize the monitor
  • Now that multi yields a PipelinedConnection, when we’re inside Namespace#multi, we no longer do synchronized calls.

Not sure where it’s best to fix this, I’ll explore a bit.

Ok, so first clue, I added some debug prints:

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'
  gem 'redis', path: "/gems/redis/redis-rb"
  gem 'redis-namespace', path: "/gems/resque/redis-namespace"
end

require 'redis'
require 'redis-namespace'

puts "Redis gem version: #{Redis::VERSION}"

key = 'a_key'
threads = []
redis = Redis.new(timeout: 5, host: 'docker.for.mac.host.internal')
redis = Redis::Namespace.new('my-namespace', redis: redis)
redis.ping
index = 0

while true do
  10.times do
    threads << Thread.new do
      1000.times do
        redis.multi do |transaction|
          transaction.incr(key)
          transaction.expire(key, 360)
        end
        p [redis.redis.class, redis.redis.instance_variable_get(:@client).class]
      end
    end
  end

  threads.each(&:join)

  puts "It works! Iteration: #{index}"
  index += 1
end

Before crash the output look like:

[Redis, Redis::Client]
[Redis, Redis::Client]
[Redis::PipelinedConnection, NilClass]
[Redis::PipelinedConnection, NilClass]

Which mean it’s the Redis::Namespace @redis variable that becomes a Redis::PipelinedConnection instance. That should help pinpoint the issue.

I also couldn’t reproduce it locally (intel macbook) but with docker it fails more often than not using ruby:3.0.1-slim

Edit: Was actually able to reproduce it locally but it is harder: it failed 3 times in 131 executions

Ok, so now the question is why it repros for you and not for me 😕

Out of curiosity, can you try:

require 'redis'
require 'redis-namespace'
key = 'a_key'
threads = []
redis = Redis.new(timeout: 5)
redis = Redis::Namespace.new('my-namespace', redis: redis)

100.times do
  threads << Thread.new do
    100.times do
      redis.multi do |transaction|
        transaction.incr(key)
        transaction.expire(key, 360)
      end
    end
  end
end

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

Intuitively I think it should reproduce much more frequently.

Your issue sounds more like: https://github.com/redis/redis-rb/issues/1088 actually.

That’s a bug indeed. I’ll figure a fix.

In the meantime you can silence deprecations.