Working once you connect the floating insertion event

3 files changed, 80 insertions, 25 deletions

diff --git a/synapse/handlers/federation_event.py b/synapse/handlers/federation_event.py
index 118aaca01d..83a438bc7e 100644
--- a/synapse/handlers/federation_event.py
+++ b/synapse/handlers/federation_event.py
@@ -717,7 +717,7 @@ class FederationEventHandler:
                 # newest) so that events are persisted before they're referenced
                 # as a `prev_event`.
                 # chronological_events,
-                reverse_chronological_events,
+                #reverse_chronological_events,
                 backfilled=True,
             )
 
@@ -1935,8 +1935,10 @@ class FederationEventHandler:
         )
 
         logger.info(
-            "_check_event_auth(event=%s) claimed_auth_events=%s calculated_auth_event_ids=%s - %s (%s)",
+            "_check_event_auth(event=%s) match=%s claimed_auth_events=%s calculated_auth_event_ids=%s - %s (%s)",
             event.event_id,
+            collections.Counter(event.auth_event_ids())
+            == collections.Counter(calculated_auth_event_ids),
             event.auth_event_ids(),
             calculated_auth_event_ids,
             event.content.get("body", event.type),
diff --git a/synapse/state/__init__.py b/synapse/state/__init__.py
index a8b91669e6..bb4dbb1edf 100644
--- a/synapse/state/__init__.py
+++ b/synapse/state/__init__.py
@@ -307,6 +307,7 @@ class StateHandler:
             state_ids_before_event,
             event.content.get("body", event.type),
             getattr(event, "state_key", None),
+            # stack_info=True,
         )
 
         if state_ids_before_event:
@@ -370,7 +371,7 @@ class StateHandler:
             state_ids_before_event = None
 
             logger.info(
-                "compute_event_context(event=%s) entry.state_group=%s state_group_before_event_prev_group=%s deltas_to_state_group_before_event=%s - %s (%s)",
+                "compute_event_context(event=%s) resolve_state_groups_for_events entry.state_group=%s state_group_before_event_prev_group=%s deltas_to_state_group_before_event=%s - %s (%s)",
                 event.event_id,
                 entry.state_group,
                 state_group_before_event_prev_group,
@@ -456,6 +457,13 @@ class StateHandler:
                     ),
                 }
             )
+            logger.info(
+                "compute_event_context(event=%s) Done creating context=%s for non-state event - %s (%s)",
+                event.event_id,
+                event_context,
+                event.content.get("body", event.type),
+                getattr(event, "state_key", None),
+            )
 
             return event_context
 
@@ -527,6 +535,11 @@ class StateHandler:
 
         state_group_ids = state_groups.values()
 
+        logger.info(
+            "resolve_state_groups_for_events: state_group_ids=%s state_groups=%s",
+            state_group_ids,
+            state_groups,
+        )
         log_kv({"state_group_ids": state_group_ids, "state_groups": state_groups})
 
         # check if each event has same state group id, if so there's no state to resolve
@@ -539,6 +552,11 @@ class StateHandler:
             ) = await self._state_storage_controller.get_state_group_delta(
                 state_group_id
             )
+            logger.info(
+                "resolve_state_groups_for_events: Returning state_group_id=%s prev_group=%s",
+                state_group_id,
+                prev_group,
+            )
             log_kv(
                 {
                     "message": "Returning state_group_id",
@@ -553,6 +571,9 @@ class StateHandler:
                 delta_ids=delta_ids,
             )
         elif len(state_group_ids_set) == 0:
+            logger.info(
+                "resolve_state_groups_for_events: Returning empty state group since there are no state_group_ids"
+            )
             log_kv(
                 {
                     "message": "Returning empty state group since there are no state_group_ids",
@@ -573,6 +594,11 @@ class StateHandler:
             None,
             state_res_store=StateResolutionStore(self.store),
         )
+        logger.info(
+            "resolve_state_groups_for_events: RResolving state groups and returning result state_to_resolve=%s result=%s",
+            state_to_resolve,
+            result,
+        )
         log_kv(
             {
                 "message": "Resolving state groups and returning result",
diff --git a/tests/handlers/test_federation_event.py b/tests/handlers/test_federation_event.py
index aab3736f04..c1458ab3dd 100644
--- a/tests/handlers/test_federation_event.py
+++ b/tests/handlers/test_federation_event.py
@@ -1020,8 +1020,12 @@ class FederationEventHandlerTests(unittest.FederatingHomeserverTestCase):
                     EventContentFields.MSC2716_NEXT_BATCH_ID: next_batch_id,
                     EventContentFields.MSC2716_HISTORICAL: True,
                 },
-                allow_no_prev_events=True,
-                prev_event_ids=[],
+                # It all works when I add a prev_event for the floating
+                # insertion event but the event no longer floats.
+                # It's able to resolve state at the prev_events though.
+                prev_event_ids=[event_before.event_id],
+                # allow_no_prev_events=True,
+                # prev_event_ids=[],
                 auth_event_ids=historical_auth_event_ids,
                 state_event_ids=historical_state_event_ids,
                 depth=inherited_depth,
@@ -1076,6 +1080,25 @@ class FederationEventHandlerTests(unittest.FederatingHomeserverTestCase):
         _add_to_known_event_list(base_insertion_event, historical_state_events)
 
         # Chronological
+        pulled_events: List[EventBase] = [
+            # Beginning of room (oldest messages)
+            # *list(state_map.values()),
+            room_create_event,
+            pl_event,
+            as_membership_event,
+            state_map.get((EventTypes.JoinRules, "")),
+            state_map.get((EventTypes.RoomHistoryVisibility, "")),
+            event_before,
+            # HISTORICAL MESSAGE END
+            insertion_event,
+            historical_message_event,
+            batch_event,
+            base_insertion_event,
+            # HISTORICAL MESSAGE START
+            event_after,
+            # Latest in the room (newest messages)
+        ]
+
         # pulled_events: List[EventBase] = [
         #     # Beginning of room (oldest messages)
         #     # *list(state_map.values()),
@@ -1098,22 +1121,22 @@ class FederationEventHandlerTests(unittest.FederatingHomeserverTestCase):
         # The order that we get after passing reverse chronological events in
         # that mostly passes. Only the insertion event is rejected but the
         # historical messages appear /messages scrollback.
-        pulled_events: List[EventBase] = [
-            # Beginning of room (oldest messages)
-            # *list(state_map.values()),
-            room_create_event,
-            pl_event,
-            as_membership_event,
-            state_map.get((EventTypes.JoinRules, "")),
-            state_map.get((EventTypes.RoomHistoryVisibility, "")),
-            event_before,
-            event_after,
-            base_insertion_event,
-            batch_event,
-            historical_message_event,
-            insertion_event,
-            # Latest in the room (newest messages)
-        ]
+        # pulled_events: List[EventBase] = [
+        #     # Beginning of room (oldest messages)
+        #     # *list(state_map.values()),
+        #     room_create_event,
+        #     pl_event,
+        #     as_membership_event,
+        #     state_map.get((EventTypes.JoinRules, "")),
+        #     state_map.get((EventTypes.RoomHistoryVisibility, "")),
+        #     event_before,
+        #     event_after,
+        #     base_insertion_event,
+        #     batch_event,
+        #     historical_message_event,
+        #     insertion_event,
+        #     # Latest in the room (newest messages)
+        # ]
 
         import logging
 
@@ -1217,8 +1240,12 @@ class FederationEventHandlerTests(unittest.FederatingHomeserverTestCase):
             )
         )
 
-        assert (
-            actual_events_in_room_chronological == expected_event_order
-        ), assertion_message
+        # assert (
+        #     actual_events_in_room_chronological == expected_event_order
+        # ), assertion_message
 
-        # self.assertEqual(actual_events_in_room_chronological, expected_event_order)
+        self.assertEqual(
+            [event.event_id for event in actual_events_in_room_chronological],
+            [event.event_id for event in expected_event_order],
+            assertion_message,
+        )