From 1040e9b6486b8b043d74edf4883711106d1e86ac Mon Sep 17 00:00:00 2001 From: David Baker Date: Fri, 5 Apr 2019 10:46:16 +0100 Subject: [PATCH] Add some logging to 3pid invite sig verification I had to add quite a lot of logging to diagnose a problem with 3pid invites - we only logged the one failure which isn't all that informative. NB. I'm not convinced the logic of this loop is right: I think it should just accept a single valid signature from a trusted source rather than fail if *any* signature is invalid. Also it should probably not skip the rest of middle loop if a check fails? However, I'm deliberately not changing the logic here. --- changelog.d/5015.misc | 1 + synapse/handlers/federation.py | 48 +++++++++++++++++++++++++++------- 2 files changed, 40 insertions(+), 9 deletions(-) create mode 100644 changelog.d/5015.misc diff --git a/changelog.d/5015.misc b/changelog.d/5015.misc new file mode 100644 index 0000000000..37fdccd0e7 --- /dev/null +++ b/changelog.d/5015.misc @@ -0,0 +1 @@ +Add logging to 3pid invite signature verification diff --git a/synapse/handlers/federation.py b/synapse/handlers/federation.py index 0684778882..1e47015d6f 100644 --- a/synapse/handlers/federation.py +++ b/synapse/handlers/federation.py @@ -1,6 +1,6 @@ # -*- coding: utf-8 -*- # Copyright 2014-2016 OpenMarket Ltd -# Copyright 2018 New Vector Ltd +# Copyright 2018, 2019 New Vector Ltd # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -2586,25 +2586,55 @@ class FederationHandler(BaseHandler): if not invite_event: raise AuthError(403, "Could not find invite") + logger.info("Checking auth on event %r", event.content) + last_exception = None + # for each public key in the 3pid invite event for public_key_object in self.hs.get_auth().get_public_keys(invite_event): try: + # for each sig on the third_party_invite block of the actual invite for server, signature_block in signed["signatures"].items(): for key_name, encoded_signature in signature_block.items(): if not key_name.startswith("ed25519:"): continue - public_key = public_key_object["public_key"] - verify_key = decode_verify_key_bytes( - key_name, - decode_base64(public_key) + logger.info( + "Attempting to verify sig with key %s from %r " + "against pubkey %r", + key_name, server, public_key_object, ) - verify_signed_json(signed, server, verify_key) - if "key_validity_url" in public_key_object: - yield self._check_key_revocation( - public_key, + + try: + public_key = public_key_object["public_key"] + verify_key = decode_verify_key_bytes( + key_name, + decode_base64(public_key) + ) + verify_signed_json(signed, server, verify_key) + logger.info( + "Successfully verified sig with key %s from %r " + "against pubkey %r", + key_name, server, public_key_object, + ) + except Exception: + logger.info( + "Failed to verify sig with key %s from %r " + "against pubkey %r", + key_name, server, public_key_object, + ) + raise + try: + if "key_validity_url" in public_key_object: + yield self._check_key_revocation( + public_key, + public_key_object["key_validity_url"] + ) + except Exception: + logger.info( + "Failed to query key_validity_url %s", public_key_object["key_validity_url"] ) + raise return except Exception as e: last_exception = e