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
pull/12933/head
Richard van der Hoff 2022-05-31 23:32:56 +01:00 committed by GitHub
parent cf05258f76
commit f0aec0abef
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 95 additions and 65 deletions

1
changelog.d/12925.misc Normal file
View File

@ -0,0 +1 @@
Improve the logging when signature checks on events fail.

View File

@ -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:

View File

@ -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

View File

@ -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(