From 17783c36d06f9bddb3d6da2c681cd10f01ac1de6 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Wed, 22 May 2024 11:19:59 -0500 Subject: [PATCH] Log why no unsigned --- synapse/handlers/sliding_sync.py | 35 +++++++++++++++---- .../storage/databases/main/events_worker.py | 10 ++++++ synapse/storage/databases/main/stream.py | 2 ++ 3 files changed, 41 insertions(+), 6 deletions(-) diff --git a/synapse/handlers/sliding_sync.py b/synapse/handlers/sliding_sync.py index 90e90fab8b..0cfc7a2a54 100644 --- a/synapse/handlers/sliding_sync.py +++ b/synapse/handlers/sliding_sync.py @@ -294,7 +294,7 @@ class SlidingSyncHandler: logger.info( "membership_change_events: %s", [ - f"{event.internal_metadata.stream_ordering}: {event.membership}" + f"{event.internal_metadata.stream_ordering}: {event.membership} ({event.event_id}: {event.type}, {event.state_key})" for event in membership_change_events ], ) @@ -347,6 +347,21 @@ class SlidingSyncHandler: logger.info("after 1: sync_room_id_set %s", sync_room_id_set) + logger.info( + "check unsigned2 %s", + [ + f"{x.event_id}->{x.unsigned}" + for x in first_membership_change_by_room_id_after_to_token.values() + ], + ) + logger.info( + "check unsigned3 %s", + [ + f"{x.event_id}->{x.unsigned}" + for x in last_membership_change_by_room_id_after_to_token.values() + ], + ) + # 2) # TODO: Verify this logic is correct for ( @@ -358,13 +373,21 @@ class SlidingSyncHandler: first_membership_change_after_to_token = ( first_membership_change_by_room_id_after_to_token.get(event.room_id, {}) ) - # TODO: Can we rely on `unsigned`? We seem to do this elsewhere in - # `calculate_user_changes()` - prev_content = first_membership_change_after_to_token.get( - "unsigned", {} - ).get("prev_content", {}) + logger.info( + "aweffaewwfeaewf %s", + first_membership_change_after_to_token.get("unsigned"), + ) + # TODO: Figure out why unsigned.prev_content isn't on the events + prev_content = first_membership_change_after_to_token.unsigned.get( + "prev_content", {} + ) prev_membership = prev_content.get("membership", None) + logger.info( + "first_membership_change_after_to_token %s", + first_membership_change_after_to_token, + ) + logger.info("prev_content %s", prev_content) logger.info("prev_membership %s", prev_membership) # 2a) Add back rooms that the user left after the `to_token` diff --git a/synapse/storage/databases/main/events_worker.py b/synapse/storage/databases/main/events_worker.py index e39d4b9624..441f204a5c 100644 --- a/synapse/storage/databases/main/events_worker.py +++ b/synapse/storage/databases/main/events_worker.py @@ -707,6 +707,10 @@ class EventsWorkerStore(SQLBaseStore): events.append(event) + logger.info( + "Returning event %s with unsigned %s", event.event_id, event.unsigned + ) + if get_prev_content: if "replaces_state" in event.unsigned: prev = await self.get_event( @@ -714,6 +718,12 @@ class EventsWorkerStore(SQLBaseStore): get_prev_content=False, allow_none=True, ) + logger.info( + "(from %s) Looking for prev=%s and found %s", + event.event_id, + event.unsigned["replaces_state"], + prev, + ) if prev: event.unsigned = dict(event.unsigned) event.unsigned["prev_content"] = prev.content diff --git a/synapse/storage/databases/main/stream.py b/synapse/storage/databases/main/stream.py index 7ab6003f61..0cd31a844c 100644 --- a/synapse/storage/databases/main/stream.py +++ b/synapse/storage/databases/main/stream.py @@ -805,6 +805,8 @@ class StreamWorkerStore(EventsWorkerStore, SQLBaseStore): [r.event_id for r in rows], get_prev_content=True ) + logger.info("check unsigned %s", [f"{x.event_id}->{x.unsigned}" for x in ret]) + return ret async def get_recent_events_for_room(