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
|
