summary refs log tree commit diff
diff options
context:
space:
mode:
authorMark Haines <mark.haines@matrix.org>2016-12-30 20:00:44 +0000
committerMark Haines <mark.haines@matrix.org>2016-12-30 20:00:44 +0000
commit0aff09f6c93193c2f3000e1e70e713f615445fe9 (patch)
treef4d5ad6fe65e70fb184b88cccd001708232e3d60
parentMerge pull request #1734 from matrix-org/markjh/fix_get_missing (diff)
downloadsynapse-0aff09f6c93193c2f3000e1e70e713f615445fe9.tar.xz
Add more useful logging when we block fetching events
-rw-r--r--synapse/federation/federation_server.py9
-rw-r--r--synapse/util/async.py5
2 files changed, 14 insertions, 0 deletions
diff --git a/synapse/federation/federation_server.py b/synapse/federation/federation_server.py
index 3fa7b2315c..6e600fcb89 100644
--- a/synapse/federation/federation_server.py
+++ b/synapse/federation/federation_server.py
@@ -538,7 +538,16 @@ class FederationServer(FederationBase):
                 if get_missing and prevs - seen:
                     # If we're missing stuff, ensure we only fetch stuff one
                     # at a time.
+                    logger.info(
+                        "Aquiring lock for room %r to fetch %d missing events: %r...",
+                        pdu.room_id, len(prevs - seen), list(prevs - seen)[:5],
+                    )
                     with (yield self._room_pdu_linearizer.queue(pdu.room_id)):
+                        logger.info(
+                            "Aquired lock for room %r to fetch %d missing events",
+                            pdu.room_id, len(prevs - seen),
+                        )
+
                         # We recalculate seen, since it may have changed.
                         have_seen = yield self.store.have_events(prevs)
                         seen = set(have_seen.keys())
diff --git a/synapse/util/async.py b/synapse/util/async.py
index 16ed183d4c..1e124163fa 100644
--- a/synapse/util/async.py
+++ b/synapse/util/async.py
@@ -23,6 +23,10 @@ from synapse.util import unwrapFirstError
 
 from contextlib import contextmanager
 
+import logging
+
+logger = logging.getLogger(__name__)
+
 
 @defer.inlineCallbacks
 def sleep(seconds):
@@ -181,6 +185,7 @@ class Linearizer(object):
         self.key_to_defer[key] = new_defer
 
         if current_defer:
+            logger.info("Waiting to aquire linearizer lock for key %r", key)
             with PreserveLoggingContext():
                 yield current_defer