diff options
-rw-r--r-- | changelog.d/6678.misc | 1 | ||||
-rw-r--r-- | synapse/handlers/devicemessage.py | 69 |
2 files changed, 67 insertions, 3 deletions
diff --git a/changelog.d/6678.misc b/changelog.d/6678.misc new file mode 100644 index 0000000000..d638ee9404 --- /dev/null +++ b/changelog.d/6678.misc @@ -0,0 +1 @@ +Check inbound to device messages for correct devices and log any inconsistencies. diff --git a/synapse/handlers/devicemessage.py b/synapse/handlers/devicemessage.py index 73b9e120f5..2fa906914c 100644 --- a/synapse/handlers/devicemessage.py +++ b/synapse/handlers/devicemessage.py @@ -19,6 +19,7 @@ from canonicaljson import json from twisted.internet import defer +import synapse from synapse.api.errors import SynapseError from synapse.logging.opentracing import ( get_active_span_text_map, @@ -31,9 +32,11 @@ from synapse.util.stringutils import random_string logger = logging.getLogger(__name__) +device_list_debugging_logger = logging.getLogger("synapse.devices.DEBUG_TRACKING") + class DeviceMessageHandler(object): - def __init__(self, hs): + def __init__(self, hs: "synapse.server.HomeServer"): """ Args: hs (synapse.server.HomeServer): server @@ -65,6 +68,9 @@ class DeviceMessageHandler(object): logger.warning("Request for keys for non-local user %s", user_id) raise SynapseError(400, "Not a user here") + if not by_device: + continue + messages_by_device = { device_id: { "content": message_content, @@ -73,8 +79,65 @@ class DeviceMessageHandler(object): } for device_id, message_content in by_device.items() } - if messages_by_device: - local_messages[user_id] = messages_by_device + local_messages[user_id] = messages_by_device + + if ( + device_list_debugging_logger.isEnabledFor(logging.INFO) + and message_type == "m.room_key_request" + ): + # If we get a request to get keys then may mean the recipient + # didn't know about the sender's device (or might just mean + # things are being a bit slow to propogate). + received_devices = set(by_device) + requesting_device_id = list(by_device.values())[0].get( + "requesting_device_id", "<unknown>" + ) + request_id = list(by_device.values())[0].get("request_id", "<unknown>") + action = list(by_device.values())[0].get("action", "<unknown>") + device_list_debugging_logger.info( + "Received room_key %s direct message (%s, %s, %s) from %s (%s) to %s (%s).", + action, + message_type, + message_id, + request_id, + sender_user_id, + requesting_device_id, + user_id, + received_devices, + ) + elif device_list_debugging_logger.isEnabledFor(logging.INFO): + # We expect the sending user to send the message to all the devices + # to the user, if they don't then that is potentially suspicious and + # so we log for debugging purposes. + + expected_devices = yield self.store.get_devices_by_user(user_id) + expected_devices = set(expected_devices) + received_devices = set(by_device) + if received_devices != {"*"} and received_devices != expected_devices: + # Devices that the remote didn't send to + missed = expected_devices - received_devices + + # Devices the remote sent to that we don't know bout + extraneous = received_devices - expected_devices + + # We try and pull out the `sender_key` from the first message, + # if it has one. This just helps figure out which device the + # message came from. + sender_key = list(by_device.values())[0].get( + "sender_key", "<unknown>" + ) + + device_list_debugging_logger.info( + "Received direct message (%s, %s) from %s (%s) to %s with mismatched devices." + " Missing: %s, extraneous: %s", + message_type, + message_id, + sender_user_id, + sender_key, + user_id, + missed, + extraneous, + ) stream_id = yield self.store.add_messages_from_remote_to_device_inbox( origin, message_id, local_messages |