Log why no unsigned

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`

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

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(