From 2615c6bd9e5456c5aefc23a9c89a4346b8afc6b0 Mon Sep 17 00:00:00 2001 From: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> Date: Wed, 5 Jun 2019 10:35:40 +0100 Subject: [PATCH] Clean up debug logging (#5347) Remove some spurious stuff, clarify some other stuff --- changelog.d/5347.misc | 2 ++ synapse/crypto/event_signing.py | 6 +++++- synapse/crypto/keyring.py | 4 ---- synapse/federation/federation_client.py | 16 +++++++++++++--- 4 files changed, 20 insertions(+), 8 deletions(-) create mode 100644 changelog.d/5347.misc diff --git a/changelog.d/5347.misc b/changelog.d/5347.misc new file mode 100644 index 0000000000..436245fb11 --- /dev/null +++ b/changelog.d/5347.misc @@ -0,0 +1,2 @@ +Various improvements to debug logging. + diff --git a/synapse/crypto/event_signing.py b/synapse/crypto/event_signing.py index 1dfa727fcf..99a586655b 100644 --- a/synapse/crypto/event_signing.py +++ b/synapse/crypto/event_signing.py @@ -31,7 +31,11 @@ logger = logging.getLogger(__name__) def check_event_content_hash(event, hash_algorithm=hashlib.sha256): """Check whether the hash for this PDU matches the contents""" name, expected_hash = compute_content_hash(event.get_pdu_json(), hash_algorithm) - logger.debug("Expecting hash: %s", encode_base64(expected_hash)) + logger.debug( + "Verifying content hash on %s (expecting: %s)", + event.event_id, + encode_base64(expected_hash), + ) # some malformed events lack a 'hashes'. Protect against it being missing # or a weird type by basically treating it the same as an unhashed event. diff --git a/synapse/crypto/keyring.py b/synapse/crypto/keyring.py index 8e1d666db1..e94e71bdad 100644 --- a/synapse/crypto/keyring.py +++ b/synapse/crypto/keyring.py @@ -866,10 +866,6 @@ def _handle_key_deferred(verify_request): json_object = verify_request.json_object - logger.debug( - "Got key %s %s:%s for server %s, verifying" - % (key_id, verify_key.alg, verify_key.version, server_name) - ) try: verify_signed_json(json_object, server_name, verify_key) except SignatureVerifyException as e: diff --git a/synapse/federation/federation_client.py b/synapse/federation/federation_client.py index d559605382..70573746d6 100644 --- a/synapse/federation/federation_client.py +++ b/synapse/federation/federation_client.py @@ -232,7 +232,8 @@ class FederationClient(FederationBase): moving to the next destination. None indicates no timeout. Returns: - Deferred: Results in the requested PDU. + Deferred: Results in the requested PDU, or None if we were unable to find + it. """ # TODO: Rate limit the number of times we try and get the same event. @@ -257,7 +258,12 @@ class FederationClient(FederationBase): destination, event_id, timeout=timeout, ) - logger.debug("transaction_data %r", transaction_data) + logger.debug( + "retrieved event id %s from %s: %r", + event_id, + destination, + transaction_data, + ) pdu_list = [ event_from_pdu_json(p, format_ver, outlier=outlier) @@ -331,7 +337,11 @@ class FederationClient(FederationBase): ) if failed_to_fetch: - logger.warn("Failed to get %r", failed_to_fetch) + logger.warning( + "Failed to fetch missing state/auth events for %s: %s", + room_id, + failed_to_fetch + ) event_map = { ev.event_id: ev for ev in fetched_events