diff --git a/changelog.d/6515.misc b/changelog.d/6515.misc new file mode 100644 index 000000000000..a9c303ed1ca2 --- /dev/null +++ b/changelog.d/6515.misc @@ -0,0 +1 @@ +Clean up some logging when handling incoming events over federation. diff --git a/synapse/handlers/federation.py b/synapse/handlers/federation.py index 8f3c9d770243..cf9c46d02758 100644 --- a/synapse/handlers/federation.py +++ b/synapse/handlers/federation.py @@ -183,7 +183,7 @@ def on_receive_pdu(self, origin, pdu, sent_to_us_directly=False): room_id = pdu.room_id event_id = pdu.event_id - logger.info("[%s %s] handling received PDU: %s", room_id, event_id, pdu) + logger.info("handling received PDU: %s", pdu) # We reprocess pdus when we have seen them only as outliers existing = yield self.store.get_event( @@ -279,9 +279,15 @@ def on_receive_pdu(self, origin, pdu, sent_to_us_directly=False): len(missing_prevs), ) - yield self._get_missing_events_for_pdu( - origin, pdu, prevs, min_depth - ) + try: + yield self._get_missing_events_for_pdu( + origin, pdu, prevs, min_depth + ) + except Exception as e: + raise Exception( + "Error fetching missing prev_events for %s: %s" + % (event_id, e) + ) # Update the set of things we've seen after trying to # fetch the missing stuff @@ -293,14 +299,6 @@ def on_receive_pdu(self, origin, pdu, sent_to_us_directly=False): room_id, event_id, ) - elif missing_prevs: - logger.info( - "[%s %s] Not recursively fetching %d missing prev_events: %s", - room_id, - event_id, - len(missing_prevs), - shortstr(missing_prevs), - ) if prevs - seen: # We've still not been able to get all of the prev_events for this event. @@ -345,6 +343,12 @@ def on_receive_pdu(self, origin, pdu, sent_to_us_directly=False): affected=pdu.event_id, ) + logger.info( + "Event %s is missing prev_events: calculating state for a " + "backwards extremity", + event_id, + ) + # Calculate the state after each of the previous events, and # resolve them to find the correct state at the current event. auth_chains = set() @@ -365,10 +369,7 @@ def on_receive_pdu(self, origin, pdu, sent_to_us_directly=False): # know about for p in prevs - seen: logger.info( - "[%s %s] Requesting state at missing prev_event %s", - room_id, - event_id, - p, + "Requesting state at missing prev_event %s", event_id, ) room_version = yield self.store.get_room_version(room_id) @@ -612,8 +613,8 @@ def _get_state_for_room(self, destination, room_id, event_id): failed_to_fetch = desired_events - event_map.keys() if failed_to_fetch: logger.warning( - "Failed to fetch missing state/auth events for %s: %s", - room_id, + "Failed to fetch missing state/auth events for %s %s", + event_id, failed_to_fetch, )