diff --git a/changelog.d/5100.misc b/changelog.d/5100.misc
new file mode 100644
index 0000000000..db5eb1b156
--- /dev/null
+++ b/changelog.d/5100.misc
@@ -0,0 +1 @@
+Improve logging when event-signature checks fail.
diff --git a/synapse/crypto/keyring.py b/synapse/crypto/keyring.py
index ed2e994437..d8ba870cca 100644
--- a/synapse/crypto/keyring.py
+++ b/synapse/crypto/keyring.py
@@ -114,40 +114,54 @@ class Keyring(object):
server_name. The deferreds run their callbacks in the sentinel
logcontext.
"""
+ # a list of VerifyKeyRequests
verify_requests = []
+ handle = preserve_fn(_handle_key_deferred)
- for server_name, json_object in server_and_json:
+ def process(server_name, json_object):
+ """Process an entry in the request list
+ Given a (server_name, json_object) pair from the request list,
+ adds a key request to verify_requests, and returns a deferred which will
+ complete or fail (in the sentinel context) when verification completes.
+ """
key_ids = signature_ids(json_object, server_name)
+
if not key_ids:
- logger.warn("Request from %s: no supported signature keys",
- server_name)
- deferred = defer.fail(SynapseError(
- 400,
- "Not signed with a supported algorithm",
- Codes.UNAUTHORIZED,
- ))
- else:
- deferred = defer.Deferred()
+ return defer.fail(
+ SynapseError(
+ 400,
+ "Not signed by %s" % (server_name,),
+ Codes.UNAUTHORIZED,
+ )
+ )
logger.debug("Verifying for %s with key_ids %s",
server_name, key_ids)
+ # add the key request to the queue, but don't start it off yet.
verify_request = VerifyKeyRequest(
- server_name, key_ids, json_object, deferred
+ server_name, key_ids, json_object, defer.Deferred(),
)
-
verify_requests.append(verify_request)
- run_in_background(self._start_key_lookups, verify_requests)
+ # now run _handle_key_deferred, which will wait for the key request
+ # to complete and then do the verification.
+ #
+ # We want _handle_key_request to log to the right context, so we
+ # wrap it with preserve_fn (aka run_in_background)
+ return handle(verify_request)
- # Pass those keys to handle_key_deferred so that the json object
- # signatures can be verified
- handle = preserve_fn(_handle_key_deferred)
- return [
- handle(rq) for rq in verify_requests
+ results = [
+ process(server_name, json_object)
+ for server_name, json_object in server_and_json
]
+ if verify_requests:
+ run_in_background(self._start_key_lookups, verify_requests)
+
+ return results
+
@defer.inlineCallbacks
def _start_key_lookups(self, verify_requests):
"""Sets off the key fetches for each verify request
diff --git a/synapse/federation/federation_base.py b/synapse/federation/federation_base.py
index dfe6b4aa5c..cffa831d80 100644
--- a/synapse/federation/federation_base.py
+++ b/synapse/federation/federation_base.py
@@ -269,7 +269,18 @@ def _check_sigs_on_pdus(keyring, room_version, pdus):
for p in pdus_to_check_sender
])
+ def sender_err(e, pdu_to_check):
+ errmsg = "event id %s: unable to verify signature for sender %s: %s" % (
+ pdu_to_check.pdu.event_id,
+ pdu_to_check.sender_domain,
+ e.getErrorMessage(),
+ )
+ # XX not really sure if these are the right codes, but they are what
+ # we've done for ages
+ raise SynapseError(400, errmsg, Codes.UNAUTHORIZED)
+
for p, d in zip(pdus_to_check_sender, more_deferreds):
+ d.addErrback(sender_err, p)
p.deferreds.append(d)
# now let's look for events where the sender's domain is different to the
@@ -291,7 +302,18 @@ def _check_sigs_on_pdus(keyring, room_version, pdus):
for p in pdus_to_check_event_id
])
+ def event_err(e, pdu_to_check):
+ errmsg = (
+ "event id %s: unable to verify signature for event id domain: %s" % (
+ pdu_to_check.pdu.event_id,
+ e.getErrorMessage(),
+ )
+ )
+ # XX as above: not really sure if these are the right codes
+ raise SynapseError(400, errmsg, Codes.UNAUTHORIZED)
+
for p, d in zip(pdus_to_check_event_id, more_deferreds):
+ d.addErrback(event_err, p)
p.deferreds.append(d)
# replace lists of deferreds with single Deferreds
|