From f0aec0abefceae36eff2ab08848e7a576535ee4e Mon Sep 17 00:00:00 2001 From: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> Date: Tue, 31 May 2022 23:32:56 +0100 Subject: Improve logging when signature checks fail (#12925) * Raise a dedicated `InvalidEventSignatureError` from `_check_sigs_on_pdu` * Downgrade logging about redactions to DEBUG this can be very spammy during a room join, and it's not very useful. * Raise `InvalidEventSignatureError` from `_check_sigs_and_hash` ... and, more importantly, move the logging out to the callers. * changelog --- changelog.d/12925.misc | 1 + synapse/federation/federation_base.py | 89 ++++++++++++++++----------------- synapse/federation/federation_client.py | 45 ++++++++++++----- synapse/federation/federation_server.py | 25 +++++++-- 4 files changed, 95 insertions(+), 65 deletions(-) create mode 100644 changelog.d/12925.misc diff --git a/changelog.d/12925.misc b/changelog.d/12925.misc new file mode 100644 index 0000000000..71ca956dc5 --- /dev/null +++ b/changelog.d/12925.misc @@ -0,0 +1 @@ +Improve the logging when signature checks on events fail. diff --git a/synapse/federation/federation_base.py b/synapse/federation/federation_base.py index 7bc54b9988..a6232e048b 100644 --- a/synapse/federation/federation_base.py +++ b/synapse/federation/federation_base.py @@ -32,6 +32,18 @@ if TYPE_CHECKING: logger = logging.getLogger(__name__) +class InvalidEventSignatureError(RuntimeError): + """Raised when the signature on an event is invalid. + + The stringification of this exception is just the error message without reference + to the event id. The event id is available as a property. + """ + + def __init__(self, message: str, event_id: str): + super().__init__(message) + self.event_id = event_id + + class FederationBase: def __init__(self, hs: "HomeServer"): self.hs = hs @@ -59,20 +71,13 @@ class FederationBase: Returns: * the original event if the checks pass * a redacted version of the event (if the signature - matched but the hash did not) + matched but the hash did not). In this case a warning will be logged. Raises: - SynapseError if the signature check failed. + InvalidEventSignatureError if the signature check failed. Nothing + will be logged in this case. """ - try: - await _check_sigs_on_pdu(self.keyring, room_version, pdu) - except SynapseError as e: - logger.warning( - "Signature check failed for %s: %s", - pdu.event_id, - e, - ) - raise + await _check_sigs_on_pdu(self.keyring, room_version, pdu) if not check_event_content_hash(pdu): # let's try to distinguish between failures because the event was @@ -87,7 +92,7 @@ class FederationBase: if set(redacted_event.keys()) == set(pdu.keys()) and set( redacted_event.content.keys() ) == set(pdu.content.keys()): - logger.info( + logger.debug( "Event %s seems to have been redacted; using our redacted copy", pdu.event_id, ) @@ -116,12 +121,13 @@ async def _check_sigs_on_pdu( ) -> None: """Check that the given events are correctly signed - Raise a SynapseError if the event wasn't correctly signed. - Args: keyring: keyring object to do the checks room_version: the room version of the PDUs pdus: the events to be checked + + Raises: + InvalidEventSignatureError if the event wasn't correctly signed. """ # we want to check that the event is signed by: @@ -147,44 +153,38 @@ async def _check_sigs_on_pdu( # First we check that the sender event is signed by the sender's domain # (except if its a 3pid invite, in which case it may be sent by any server) + sender_domain = get_domain_from_id(pdu.sender) if not _is_invite_via_3pid(pdu): try: await keyring.verify_event_for_server( - get_domain_from_id(pdu.sender), + sender_domain, pdu, pdu.origin_server_ts if room_version.enforce_key_validity else 0, ) except Exception as e: - errmsg = "event id %s: unable to verify signature for sender %s: %s" % ( + raise InvalidEventSignatureError( + f"unable to verify signature for sender domain {sender_domain}: {e}", pdu.event_id, - get_domain_from_id(pdu.sender), - e, - ) - raise SynapseError(403, errmsg, Codes.FORBIDDEN) + ) from None # now let's look for events where the sender's domain is different to the # event id's domain (normally only the case for joins/leaves), and add additional # checks. Only do this if the room version has a concept of event ID domain # (ie, the room version uses old-style non-hash event IDs). - if room_version.event_format == EventFormatVersions.V1 and get_domain_from_id( - pdu.event_id - ) != get_domain_from_id(pdu.sender): - try: - await keyring.verify_event_for_server( - get_domain_from_id(pdu.event_id), - pdu, - pdu.origin_server_ts if room_version.enforce_key_validity else 0, - ) - except Exception as e: - errmsg = ( - "event id %s: unable to verify signature for event id domain %s: %s" - % ( - pdu.event_id, - get_domain_from_id(pdu.event_id), - e, + if room_version.event_format == EventFormatVersions.V1: + event_domain = get_domain_from_id(pdu.event_id) + if event_domain != sender_domain: + try: + await keyring.verify_event_for_server( + event_domain, + pdu, + pdu.origin_server_ts if room_version.enforce_key_validity else 0, ) - ) - raise SynapseError(403, errmsg, Codes.FORBIDDEN) + except Exception as e: + raise InvalidEventSignatureError( + f"unable to verify signature for event domain {event_domain}: {e}", + pdu.event_id, + ) from None # If this is a join event for a restricted room it may have been authorised # via a different server from the sending server. Check those signatures. @@ -204,15 +204,10 @@ async def _check_sigs_on_pdu( pdu.origin_server_ts if room_version.enforce_key_validity else 0, ) except Exception as e: - errmsg = ( - "event id %s: unable to verify signature for authorising server %s: %s" - % ( - pdu.event_id, - authorising_server, - e, - ) - ) - raise SynapseError(403, errmsg, Codes.FORBIDDEN) + raise InvalidEventSignatureError( + f"unable to verify signature for authorising serve {authorising_server}: {e}", + pdu.event_id, + ) from None def _is_invite_via_3pid(event: EventBase) -> bool: diff --git a/synapse/federation/federation_client.py b/synapse/federation/federation_client.py index b60b8983ea..ad475a913b 100644 --- a/synapse/federation/federation_client.py +++ b/synapse/federation/federation_client.py @@ -54,7 +54,11 @@ from synapse.api.room_versions import ( RoomVersions, ) from synapse.events import EventBase, builder -from synapse.federation.federation_base import FederationBase, event_from_pdu_json +from synapse.federation.federation_base import ( + FederationBase, + InvalidEventSignatureError, + event_from_pdu_json, +) from synapse.federation.transport.client import SendJoinResponse from synapse.http.types import QueryParams from synapse.types import JsonDict, UserID, get_domain_from_id @@ -319,7 +323,13 @@ class FederationClient(FederationBase): pdu = pdu_list[0] # Check signatures are correct. - signed_pdu = await self._check_sigs_and_hash(room_version, pdu) + try: + signed_pdu = await self._check_sigs_and_hash(room_version, pdu) + except InvalidEventSignatureError as e: + errmsg = f"event id {pdu.event_id}: {e}" + logger.warning("%s", errmsg) + raise SynapseError(403, errmsg, Codes.FORBIDDEN) + return signed_pdu return None @@ -555,20 +565,24 @@ class FederationClient(FederationBase): Returns: The PDU (possibly redacted) if it has valid signatures and hashes. + None if no valid copy could be found. """ - res = None try: - res = await self._check_sigs_and_hash(room_version, pdu) - except SynapseError: - pass - - if not res: - # Check local db. - res = await self.store.get_event( - pdu.event_id, allow_rejected=True, allow_none=True + return await self._check_sigs_and_hash(room_version, pdu) + except InvalidEventSignatureError as e: + logger.warning( + "Signature on retrieved event %s was invalid (%s). " + "Checking local store/orgin server", + pdu.event_id, + e, ) + # Check local db. + res = await self.store.get_event( + pdu.event_id, allow_rejected=True, allow_none=True + ) + pdu_origin = get_domain_from_id(pdu.sender) if not res and pdu_origin != origin: try: @@ -1043,9 +1057,14 @@ class FederationClient(FederationBase): pdu = event_from_pdu_json(pdu_dict, room_version) # Check signatures are correct. - pdu = await self._check_sigs_and_hash(room_version, pdu) + try: + pdu = await self._check_sigs_and_hash(room_version, pdu) + except InvalidEventSignatureError as e: + errmsg = f"event id {pdu.event_id}: {e}" + logger.warning("%s", errmsg) + raise SynapseError(403, errmsg, Codes.FORBIDDEN) - # FIXME: We should handle signature failures more gracefully. + # FIXME: We should handle signature failures more gracefully. return pdu diff --git a/synapse/federation/federation_server.py b/synapse/federation/federation_server.py index 3ecede22d9..12591dc8db 100644 --- a/synapse/federation/federation_server.py +++ b/synapse/federation/federation_server.py @@ -48,7 +48,11 @@ from synapse.api.room_versions import KNOWN_ROOM_VERSIONS, RoomVersion from synapse.crypto.event_signing import compute_event_signature from synapse.events import EventBase from synapse.events.snapshot import EventContext -from synapse.federation.federation_base import FederationBase, event_from_pdu_json +from synapse.federation.federation_base import ( + FederationBase, + InvalidEventSignatureError, + event_from_pdu_json, +) from synapse.federation.persistence import TransactionActions from synapse.federation.units import Edu, Transaction from synapse.http.servlet import assert_params_in_dict @@ -631,7 +635,12 @@ class FederationServer(FederationBase): pdu = event_from_pdu_json(content, room_version) origin_host, _ = parse_server_name(origin) await self.check_server_matches_acl(origin_host, pdu.room_id) - pdu = await self._check_sigs_and_hash(room_version, pdu) + try: + pdu = await self._check_sigs_and_hash(room_version, pdu) + except InvalidEventSignatureError as e: + errmsg = f"event id {pdu.event_id}: {e}" + logger.warning("%s", errmsg) + raise SynapseError(403, errmsg, Codes.FORBIDDEN) ret_pdu = await self.handler.on_invite_request(origin, pdu, room_version) time_now = self._clock.time_msec() return {"event": ret_pdu.get_pdu_json(time_now)} @@ -864,7 +873,12 @@ class FederationServer(FederationBase): ) ) - event = await self._check_sigs_and_hash(room_version, event) + try: + event = await self._check_sigs_and_hash(room_version, event) + except InvalidEventSignatureError as e: + errmsg = f"event id {event.event_id}: {e}" + logger.warning("%s", errmsg) + raise SynapseError(403, errmsg, Codes.FORBIDDEN) return await self._federation_event_handler.on_send_membership_event( origin, event @@ -1016,8 +1030,9 @@ class FederationServer(FederationBase): # Check signature. try: pdu = await self._check_sigs_and_hash(room_version, pdu) - except SynapseError as e: - raise FederationError("ERROR", e.code, e.msg, affected=pdu.event_id) + except InvalidEventSignatureError as e: + logger.warning("event id %s: %s", pdu.event_id, e) + raise FederationError("ERROR", 403, str(e), affected=pdu.event_id) if await self._spam_checker.should_drop_federated_event(pdu): logger.warning( -- cgit 1.4.1