diff --git a/synapse/storage/events.py b/synapse/storage/events.py index ecb79c07ef86..04dbdac3f8a8 100644 --- a/synapse/storage/events.py +++ b/synapse/storage/events.py @@ -1084,8 +1084,10 @@ def _enqueue_events(self, events, check_redacted=True, allow_rejected=False): self._do_fetch ) + logger.info("Loading %d events", len(events)) with PreserveLoggingContext(): rows = yield events_d + logger.info("Loaded %d events (%d rows)", len(events), len(rows)) if not allow_rejected: rows[:] = [r for r in rows if not r["rejects"]] diff --git a/synapse/util/async.py b/synapse/util/async.py index 4280455cbe95..83875edc8567 100644 --- a/synapse/util/async.py +++ b/synapse/util/async.py @@ -166,7 +166,11 @@ class Linearizer(object): # do some work. """ - def __init__(self): + def __init__(self, name=None): + if name is None: + self.name = id(self) + else: + self.name = name self.key_to_defer = {} @defer.inlineCallbacks @@ -185,15 +189,20 @@ def queue(self, key): self.key_to_defer[key] = new_defer if current_defer: - logger.info("Waiting to acquire linearizer lock for key %r", key) + logger.info( + "Waiting to acquire linearizer lock %r for key %r", self.name, key + ) with PreserveLoggingContext(): yield current_defer + logger.info("Acquired linearizer lock %r for key %r", self.name, key) + @contextmanager def _ctx_manager(): try: yield finally: + logger.info("Releasing linearizer lock %r for key %r", self.name, key) new_defer.callback(None) current_d = self.key_to_defer.get(key) if current_d is new_defer: