caches: improved locking problems with distributed lock new cache backend

vcsserver/lib/_vendor/redis_lock/__init__.py

@@ -10,7 +10,7 b' from redis import StrictRedis'
 __version__ = '3.7.0'
 
 loggers = {
-    k: getLogger("vcsserver" + ".".join((__name__, k)))
+    k: getLogger("vcsserver." + ".".join((__name__, k)))
     for k in [
         "acquire",
         "refresh.thread.start",
@@ -221,10 +221,11 b' class Lock(object):'
         """
         logger = loggers["acquire"]
 
-        logger.debug("Getting %r ...", self._name)
+        logger.debug("Getting acquire on %r ...", self._name)
 
         if self._held:
-            raise AlreadyAcquired("Already acquired from this Lock instance.")
+            owner_id = self.get_owner_id()
+            raise AlreadyAcquired("Already acquired from this Lock instance. Lock id: {}".format(owner_id))
 
         if not blocking and timeout is not None:
             raise TimeoutNotUsable("Timeout cannot be used if blocking=False")

vcsserver/lib/rc_cache/backends.py

@@ -124,7 +124,14 b' class FileNamespaceBackend(PickleSeriali'
 
     def __init__(self, arguments):
         arguments['lock_factory'] = CustomLockFactory
+        db_file = arguments.get('filename')
+
+        log.debug('initialing %s DB in %s', self.__class__.__name__, db_file)
+        try:
         super(FileNamespaceBackend, self).__init__(arguments)
+        except Exception:
+            log.error('Failed to initialize db at: %s', db_file)
+            raise
 
     def __repr__(self):
         return '{} `{}`'.format(self.__class__, self.filename)
@@ -141,13 +148,16 b' class FileNamespaceBackend(PickleSeriali'
             return False
 
         with self._dbm_file(True) as dbm:
-
+            try:
             return filter(cond, dbm.keys())
+            except Exception:
+                log.error('Failed to fetch DBM keys from DB: %s', self.get_store())
+                raise
 
     def get_store(self):
         return self.filename
 
-    def get(self, key):
+    def _dbm_get(self, key):
         with self._dbm_file(False) as dbm:
             if hasattr(dbm, 'get'):
                 value = dbm.get(key, NO_VALUE)
@@ -161,6 +171,13 b' class FileNamespaceBackend(PickleSeriali'
                 value = self._loads(value)
             return value
 
+    def get(self, key):
+        try:
+            return self._dbm_get(key)
+        except Exception:
+            log.error('Failed to fetch DBM key %s from DB: %s', key, self.get_store())
+            raise
+
     def set(self, key, value):
         with self._dbm_file(True) as dbm:
             dbm[key] = self._dumps(value)
@@ -235,17 +252,16 b' class BaseRedisBackend(redis_backend.Red'
 
     def get_mutex(self, key):
         if self.distributed_lock:
-            import redis_lock
             lock_key = redis_backend.u('_lock_{0}').format(key)
             log.debug('Trying to acquire Redis lock for key %s', lock_key)
-            lock = redis_lock.Lock(
-                redis_client=self.client,
-                name=lock_key,
-                expire=self.lock_timeout,
-                auto_renewal=False,
-                strict=True,
-            )
-            return lock
+
+            auto_renewal = True
+            lock_timeout = self.lock_timeout
+            if auto_renewal and not self.lock_timeout:
+                # set default timeout for auto_renewal
+                lock_timeout = 10
+            return get_mutex_lock(self.client, lock_key, lock_timeout,
+                                  auto_renewal=auto_renewal)
         else:
             return None
 
@@ -258,3 +274,34 b' class RedisPickleBackend(PickleSerialize'
 class RedisMsgPackBackend(MsgPackSerializer, BaseRedisBackend):
     key_prefix = 'redis_msgpack_backend'
     pass
+
+
+def get_mutex_lock(client, lock_key, lock_timeout, auto_renewal=False):
+    import redis_lock
+
+    class _RedisLockWrapper(object):
+        """LockWrapper for redis_lock"""
+
+        def __init__(self):
+            pass
+
+        @property
+        def lock(self):
+            return redis_lock.Lock(
+                redis_client=client,
+                name=lock_key,
+                expire=lock_timeout,
+                auto_renewal=auto_renewal,
+                strict=True,
+            )
+
+        def acquire(self, wait=True):
+            return self.lock.acquire(wait)
+
+        def release(self):
+            try:
+                self.lock.release()
+            except redis_lock.NotAcquired:
+                pass
+
+    return _RedisLockWrapper()