add logging for all the places we call resolve_state_groups. my kingdom for a backtrace that actually works.

3 files changed, 6 insertions, 0 deletions

diff --git a/synapse/api/auth.py b/synapse/api/auth.py
index a99986714d..641f2bb065 100644
--- a/synapse/api/auth.py
+++ b/synapse/api/auth.py
@@ -290,6 +290,7 @@ class Auth(object):
         with Measure(self.clock, "check_host_in_room"):
             latest_event_ids = yield self.store.get_latest_event_ids_in_room(room_id)
 
+            logger.info("calling resolve_state_groups from check_host_in_room");
             entry = yield self.state.resolve_state_groups(
                 room_id, latest_event_ids
             )
diff --git a/synapse/handlers/federation.py b/synapse/handlers/federation.py
index 8c93d6d39f..9ed708bf3e 100644
--- a/synapse/handlers/federation.py
+++ b/synapse/handlers/federation.py
@@ -591,6 +591,7 @@ class FederationHandler(BaseHandler):
 
         event_ids = list(extremities.keys())
 
+        logger.info("Calling resolve_state_groups in _maybe_backfill")
         states = yield preserve_context_over_deferred(defer.gatherResults([
             preserve_fn(self.state_handler.resolve_state_groups)(room_id, [e])
             for e in event_ids
diff --git a/synapse/state.py b/synapse/state.py
index b4eca0e5d5..bbca59b1e8 100644
--- a/synapse/state.py
+++ b/synapse/state.py
@@ -123,6 +123,7 @@ class StateHandler(object):
         if not latest_event_ids:
             latest_event_ids = yield self.store.get_latest_event_ids_in_room(room_id)
 
+        logger.info("calling resolve_state_groups from get_current_state");
         ret = yield self.resolve_state_groups(room_id, latest_event_ids)
         state = ret.state
 
@@ -147,6 +148,7 @@ class StateHandler(object):
         if not latest_event_ids:
             latest_event_ids = yield self.store.get_latest_event_ids_in_room(room_id)
 
+        logger.info("calling resolve_state_groups from get_current_state_ids");
         ret = yield self.resolve_state_groups(room_id, latest_event_ids)
         state = ret.state
 
@@ -158,6 +160,7 @@ class StateHandler(object):
 
     @defer.inlineCallbacks
     def get_current_user_in_room(self, room_id, latest_event_ids=None):
+        logger.info("calling resolve_state_groups from get_current_user_in_room");
         if not latest_event_ids:
             latest_event_ids = yield self.store.get_latest_event_ids_in_room(room_id)
         entry = yield self.resolve_state_groups(room_id, latest_event_ids)
@@ -223,6 +226,7 @@ class StateHandler(object):
             context.prev_state_events = []
             defer.returnValue(context)
 
+        logger.info("calling resolve_state_groups from compute_event_context");
         if event.is_state():
             entry = yield self.resolve_state_groups(
                 event.room_id, [e for e, _ in event.prev_events],