From da87def3998522722630142ff4f741edc506af97 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 6 Oct 2022 23:40:25 -0500 Subject: [PATCH] Consistently handle `NotRetryingDestination` and `FederationDeniedError` --- synapse/federation/federation_client.py | 43 ++++++++++++------------- synapse/handlers/federation.py | 14 ++++---- synapse/util/retryutils.py | 2 +- 3 files changed, 30 insertions(+), 29 deletions(-) diff --git a/synapse/federation/federation_client.py b/synapse/federation/federation_client.py index 940bc44d1cb7..f2d767ba9e5b 100644 --- a/synapse/federation/federation_client.py +++ b/synapse/federation/federation_client.py @@ -366,7 +366,7 @@ async def _record_failure_callback( @tag_args async def get_pdu( self, - destinations: Iterable[str], + destinations: Collection[str], event_id: str, room_version: RoomVersion, timeout: Optional[int] = None, @@ -389,7 +389,7 @@ async def get_pdu( """ logger.debug( - "get_pdu: event_id=%s from destinations=%s", event_id, destinations + f"get_pdu(event_id={event_id}): from destinations=%s", destinations ) # TODO: Rate limit the number of times we try and get the same event. @@ -415,11 +415,7 @@ async def get_pdu( last_attempt = pdu_attempts.get(destination, 0) if last_attempt + PDU_RETRY_TIME_MS > now: logger.debug( - "get_pdu: skipping destination=%s because we tried it recently last_attempt=%s and we only check every %s (now=%s)", - destination, - last_attempt, - PDU_RETRY_TIME_MS, - now, + f"get_pdu(event_id={event_id}): skipping destination={destination} because we tried it recently last_attempt={last_attempt} and we only check every {PDU_RETRY_TIME_MS} (now={now})", ) continue @@ -442,25 +438,24 @@ async def get_pdu( # loop and stop asking other destinations. break - except SynapseError as e: + except NotRetryingDestination as e: + logger.info(f"get_pdu(event_id={event_id}): {e}") + continue + except FederationDeniedError: logger.info( - "Failed to get PDU %s from %s because %s", - event_id, - destination, - e, + f"get_pdu(event_id={event_id}): Not attempting to fetch PDU from {destination} because the homeserver is not on our federation whitelist" ) continue - except (NotRetryingDestination, FederationDeniedError) as e: - logger.info(str(e)) + except SynapseError as e: + logger.info( + f"get_pdu(event_id={event_id}): Failed to get PDU from {destination} because {e}", + ) continue except Exception as e: pdu_attempts[destination] = now logger.info( - "Failed to get PDU %s from %s because %s", - event_id, - destination, - e, + f"get_pdu(event_id={event_id}): Failed to get PDU from {destination} because {e}", ) continue @@ -834,14 +829,18 @@ async def _try_destination_list( except ( RequestSendFailed, InvalidResponseError, - # This is the federation client retry backoff error. - NotRetryingDestination, - # Homeserver is not on our whitelist. - FederationDeniedError, ) as e: logger.warning("Failed to %s via %s: %s", description, destination, e) # Skip to the next homeserver in the list to try. continue + except NotRetryingDestination as e: + logger.info(f"{description}: {e}") + continue + except FederationDeniedError: + logger.info( + f"{description}: Not attempting to {description} from {destination} because the homeserver is not on our federation whitelist" + ) + continue except UnsupportedRoomVersionError: raise except HttpResponseException as e: diff --git a/synapse/handlers/federation.py b/synapse/handlers/federation.py index 986ffed3d592..1d5baebfc5b4 100644 --- a/synapse/handlers/federation.py +++ b/synapse/handlers/federation.py @@ -441,6 +441,14 @@ async def try_backfill(domains: Collection[str]) -> bool: # appropriate stuff. # TODO: We can probably do something more intelligent here. return True + except NotRetryingDestination as e: + logger.info(f"_maybe_backfill_inner: {e}") + continue + except FederationDeniedError: + logger.info( + f"_maybe_backfill_inner: Not attempting to backfill from {dom} because the homeserver is not on our federation whitelist" + ) + continue except (SynapseError, InvalidResponseError) as e: logger.info("Failed to backfill from %s because %s", dom, e) continue @@ -476,15 +484,9 @@ async def try_backfill(domains: Collection[str]) -> bool: logger.info("Failed to backfill from %s because %s", dom, e) continue - except NotRetryingDestination as e: - logger.info(str(e)) - continue except RequestSendFailed as e: logger.info("Failed to get backfill from %s because %s", dom, e) continue - except FederationDeniedError as e: - logger.info(e) - continue except Exception as e: logger.exception("Failed to backfill from %s because %s", dom, e) continue diff --git a/synapse/util/retryutils.py b/synapse/util/retryutils.py index d0a69ff843e5..dcc037b9822e 100644 --- a/synapse/util/retryutils.py +++ b/synapse/util/retryutils.py @@ -51,7 +51,7 @@ def __init__(self, retry_last_ts: int, retry_interval: int, destination: str): destination: the domain in question """ - msg = "Not retrying server %s." % (destination,) + msg = f"Not retrying server {destination} because we tried it recently retry_last_ts={retry_last_ts} and we won't check for another retry_interval={retry_interval}ms." super().__init__(msg) self.retry_last_ts = retry_last_ts