Concurrency issue in redis-rb 4.6.0 (using redis-namespace)

[sergio91pt]

With the upgrade of redis-rb from 4.5.1 to 4.6.0 we started observing ocasional odd behavior under load:

A non-pipelined redis.evalsha(sha, keys, args) returning a Redis::Future instead of a String causing an error when the application tries to parse it.

And occasionally at the same time but in a different thread we noticed a misbehavior when a pipelined exists? wrongly evaluates to true.

(open, half_open) = execute_redis_pipeline { |pipeline|
  pipeline.exists?(open_key(name))
  pipeline.exists?(half_open_key(name))
}
# Both should be false according to our observability metrics

# For reference:
def execute_redis_command
  yield
rescue Redis::BaseError => e
  raise CircuitBreakerError.new(e.message, e)
end

def execute_redis_pipeline(&block)
  execute_redis_command { redis.pipelined(&block) }
end

Although relatively rare they seem related with the redis-rb gem upgrade, since we updated our pipelines and sidekiq dependency to avoid deprecation warnings 1 week before upgrading redis-rb, without problem.

Using:

Ruby 3.0.1
connection_pool (2.2.5)
redis (4.6.0) (default driver, w/ redis sentinel, no cluster)
redis-namespace (1.8.1)
sidekiq (6.4.1)
sidekiq-pro (5.3.1)
newrelic_rpm (7.2.0)

[byroot]

returning a Redis::Future instead of a String causing an error when the application tries to parse it.

That would suggest that the ensure block wouldn't be executed somehow:

redis-rb/lib/redis.rb

Lines 171 to 172 in 610c783

	ensure
	@client = prior_client

Do you use Timeout.timeout?

I'd suggest something to your connection pool to make sure redis.instance_variable_get(:@client) is not a pipeline, that should help pinpoint where the leak happens.

[sergio91pt]

Thanks for the quick response.
We don't use Timeout.timeout and a quick look at the connection_pool code, it also isn't used there, only ConditionVariable#wait.

[byroot]

It's possible some other gem might use it. Either way, short term I really recomend the modified connection pool, both to find the source of the problem, and to negate it's impact.

Basically when the connection is checked back in the pool, you want to inspect it to make sure a pipeline didn't leak.

I reviewed the code, and there's no fundamental change on how pipelined is handled, so I don't see anything specific to 4.6.0 that could cause this. But if you do find some more clues, I'm all ears.

[casperisfine]

Most of the discussion on this issue actually happened on an unrelated one: #1069 (comment)

[byroot]

redis-namespace 1.8.2 is out: https://rubygems.org/gems/redis-namespace/versions/1.8.2