lots of updates

synapse/handlers/sync.py

@@ -1222,12 +1222,7 @@ async def _compute_state_delta_for_full_sync(
 
         if client_state_desync_logger.isEnabledFor(logging.WARNING):
             await self._log_client_state_desync(
-                room_id,
-                {},
-                state_at_timeline_end,
-                state_ids,
-                timeline_state,
-                state_filter,
+                room_id, None, state_ids, timeline_state, lazy_load_members
             )
 
         return state_ids
@@ -1333,11 +1328,10 @@ async def _compute_state_delta_for_incremental_sync(
         if client_state_desync_logger.isEnabledFor(logging.WARNING):
             await self._log_client_state_desync(
                 room_id,
-                {},
-                state_at_timeline_end,
+                since_token,
                 state_ids,
                 timeline_state,
-                state_filter,
+                lazy_load_members,
             )
 
         return state_ids
@@ -1459,50 +1453,96 @@ async def _find_missing_partial_state_memberships(
     async def _log_client_state_desync(
         self,
         room_id: str,
-        state_at_previous_timeline_end: StateMap[str],
-        state_at_timeline_end: StateMap[str],
+        since_token: Optional[StreamToken],
         sync_response_state_state: StateMap[str],
         sync_response_timeline_state: StateMap[str],
-        state_filter: StateFilter,
+        lazy_load_members: bool,
     ) -> None:
-        # Tracking to see how often https://github.com/matrix-org/matrix-spec/issues/1209 bites
+        # Tracking to see how often the client's state gets out of sync with the
+        # actual current state of the room.
         #
-        # Clients are supposed to be able to track the state of the room by applying all of
-        # the state updates they see to their in-memory state map. We are interested in
-        # knowing how often that algorithm fails.
-        client_calculated_state = dict(state_at_previous_timeline_end)
-        client_calculated_state.update(sync_response_state_state)
-        client_calculated_state.update(sync_response_timeline_state)
-
-        spec1209_error = await self._calculate_state_error(
-            state_at_timeline_end, client_calculated_state, state_filter
-        )
-        if spec1209_error:
-            logger.warning(
-                "matrix-spec#1209 discrepancy in room %s: %s",
-                room_id,
-                spec1209_error,
+        # There are few different potential failure modes here:
+        #
+        #  * State resolution can cause changes in the state of the room that don't
+        #    directly correspond to events with the corresponding (type, state_key).
+        #    https://github.com/matrix-org/matrix-spec/issues/1209 discusses this in
+        #    more detail.
+        #
+        #  * Even where there is an event that causes a given state change, Synapse
+        #    may not serve it to the client, since it works on state at specific points
+        #    in the DAG, rather than "current state".
+        #    See https://github.com/element-hq/synapse/issues/16940.
+        #
+        #  * Lazy-loading adds more complexity, as it means that events that would
+        #    normally be served via the `state` part of an incremental sync are filtered
+        #    out.
+        #
+        # To try to get a handle on this, let's put ourselves in the shoes of a client,
+        # and compare the state they will calculate against the actual current state.
+
+        if since_token is None:
+            if lazy_load_members:
+                # For initial syncs with lazy-loading enabled, there's not too much
+                # concern here. We know the client will do a `/members` query before
+                # doing any encryption, so what sync returns isn't too important.
+                #
+                # (Of course, then `/members` might also return an incomplete list, but
+                # that's a separate problem.)
+                return
+
+            # For regular initial syncs, compare the returned response with the actual
+            # current state.
+            client_calculated_state = {}
+            client_calculated_state.update(sync_response_state_state)
+            client_calculated_state.update(sync_response_timeline_state)
+
+            current_state = await self._state_storage_controller.get_current_state_ids(
+                room_id, await_full_state=False
+            )
+            state_error = await self._calculate_state_error(
+                current_state, client_calculated_state
+            )
+            if state_error:
+                client_state_desync_logger.warning(
+                    "client state discrepancy in initialsync in room %s: %s",
+                    room_id,
+                    state_error,
+                )
+        else:
+            # For an incremental (gappy or otherwise) sync, let's assume the client has
+            # a complete membership list as of the last sync (or rather, at
+            # `since_token`, which is the closes approximation we have to it
+            # right now), and see what they would calculate as the current state given
+            # this sync update.
+
+            client_calculated_state = dict(
+                await self.get_state_at(
+                    room_id,
+                    stream_position=since_token,
+                    await_full_state=False,
+                )
             )
+            client_calculated_state.update(sync_response_state_state)
+            client_calculated_state.update(sync_response_timeline_state)
 
-        # A similar calculation for https://github.com/element-hq/synapse/issues/16940
-        current_state = await self._state_storage_controller.get_current_state_ids(
-            room_id, state_filter, await_full_state=False
-        )
-        synapse_16940_error = await self._calculate_state_error(
-            current_state, client_calculated_state, state_filter
-        )
-        if synapse_16940_error:
-            logger.warning(
-                "synapse#16940 discrepancy in room %s: %s",
-                room_id,
-                synapse_16940_error,
+            current_state = await self._state_storage_controller.get_current_state_ids(
+                room_id, await_full_state=False
+            )
+
+            state_error = await self._calculate_state_error(
+                current_state, client_calculated_state
             )
+            if state_error:
+                client_state_desync_logger.warning(
+                    "client state discrepancy in room %s: %s",
+                    room_id,
+                    state_error,
+                )
 
     async def _calculate_state_error(
         self,
         actual_state: StateMap[str],
         client_calculated_state: StateMap[str],
-        state_filter: StateFilter,
     ) -> Mapping[str, ClientCalculatedMembershipStateErrorEntry]:
         error_map: Dict[str, ClientCalculatedMembershipStateErrorEntry] = {}
 
@@ -1513,16 +1553,10 @@ async def event_id_to_membership(event_id: Optional[str]) -> Optional[str]:
             return event.membership
 
         # Check for entries in the calculated state which differ from the actual state.
-        #
-        # We ignore entries that are excluded by the lazy-loading filter, since we know
-        # they won't be in the actual_state map.
-        # XXX: this isn't actually very helpful :(.
         for (
             event_type,
             state_key,
-        ), calculated_event_id in state_filter.filter_state(
-            client_calculated_state
-        ).items():
+        ), calculated_event_id in client_calculated_state.items():
             if event_type != EventTypes.Member:
                 continue