Flushing db leads to setting huge numbers of _lock keys in distributed architecture even when required key is present

[snjtkh]

We have like 30 consumers which are processing gcp pubsub data and some 4-5 web apps which are talking to redis. Everything works fine but whenever load spikes on consumers and in between if a key is expired then after setting the missed key(which is used in every consumer) it started setting _lock_key a lot which remains there until its ttl (after one expired another is set for the same key) even when required key is present. We have set expiration_time=-1 for the region.

 region = make_region(function_key_generator=kwarg_function_key_generator).configure(
    'dogpile.cache.redis',
    arguments={
                'redis_expiration_time': 60 * 60 * 8,  # 8 hours,
                'distributed_lock': True,
                'thread_local_lock': False,
                'lock_timeout': 60,
                'connection_pool': redis.BlockingConnectionPool(max_connections=50, timeout=20,
                                                queue_class=LifoQueue).from_url(os.environ['REDIS_HOST'] + '? 
                                            health_check_interval=30&retry_on_timeout=Yes&socket_timeout=20&socket_connect_timeout=10') 
                                            if gevent.monkey.is_anything_patched() else redis.BlockingConnectionPool(max_connections=50, 
                                            timeout=20).from_url(os.environ['REDIS_HOST'] + '? 
                                            health_check_interval=30&retry_on_timeout=Yes&socket_timeout=20&socket_connect_timeout=10')
                             },
    expiration_time=-1
)

@region.cache_on_arguments()
def test(data=None):
       return data

Setting bulk lock keys also spiking redis memory, isn't it some kind of thunderherd. Is it a bug or i am doing something in wrong way, please help me in understanding this behaviour.

[zzzeek]

cc @jvanasco

[jvanasco]

This stuff is really hard to debug and build repeatable test cases for.

I would try to recreate the problem on a local development server, then edit the source for dogpile and redis to log/print a lot of information. based on that you should be able to figure out what is going on, or how to build a SSCEE to share here.

this sort of reminds me of a race condition when:

• a lock that times out in Redis
• the generator returns a value
• there is an exception because either the first lock no longer exists OR a second lock now belongs to a new process that was spawned after the first lock expired.

a)

00s Lock is created (redis.py)
05s Lock is timed out (in Redis)
06.0s Value returns (redis.py)
06.1s release() called; LockError is raised due to non-existent lock

b)

00s Lock is created (redis.py)
05s Lock is timed out (in Redis)
06.0s Value returns (redis.py)
06.1s Second Lock for same Key is created (redis.py) by another processes
06.2s release() called on first Lock; LockError is raised due to the lock belong to the second process