Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Improve logging and opentracing for to-device message handling #14598

Merged
merged 9 commits into from
Dec 6, 2022
Merged

Improve logging and opentracing for to-device message handling #14598

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
76d44db
Stop adding a `message_id` to to-device messages
richvdh Dec 2, 2022
3d88474
Rename Opentracing tag for to-device EDUs
richvdh Dec 2, 2022
85954d9
Define some new opentracing tags
richvdh Dec 2, 2022
f7ababb
Improve opentracing in `/sendToDevice` handler
richvdh Dec 2, 2022
64eb08a
Improve opentracing and logging for outgoing to-device messages
richvdh Dec 2, 2022
7a2ff37
Improve opentracing and logging for received to-device message
richvdh Dec 2, 2022
8fbdd8b
Improve opentracing and logging for serving to-device messages
richvdh Dec 2, 2022
d7ae20e
changelog
richvdh Dec 2, 2022
8cdc1b1
Fix test
richvdh Dec 2, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 0 additions & 3 deletions synapse/handlers/appservice.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -578,9 +578,6 @@ async def _get_to_device_messages(
device_id,
), messages in recipient_device_to_messages.items():
for message_json in messages:
# Remove 'message_id' from the to-device message, as it's an internal ID
message_json.pop("message_id", None)

message_payload.append(
{
"to_user_id": user_id,
Expand Down
10 changes: 5 additions & 5 deletions synapse/handlers/devicemessage.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -216,9 +216,6 @@ async def send_device_message(
"""
sender_user_id = requester.user.to_string()

message_id = random_string(16)
set_tag(SynapseTags.TO_DEVICE_MESSAGE_ID, message_id)

log_kv({"number_of_to_device_messages": len(messages)})
set_tag("sender", sender_user_id)
local_messages = {}
Expand Down Expand Up @@ -247,7 +244,6 @@ async def send_device_message(
"content": message_content,
"type": message_type,
"sender": sender_user_id,
"message_id": message_id,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do seem to use this over federation?

synapse/synapse/handlers/devicemessage.py

Line 108 in de6bb61

message_id = content["message_id"]

Or am I misreading the code? (It looks like there are more places we use message_id in general?)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do seem to use this over federation?

yes, but this code is for handling local user -> local user DMs (see the condition at line 244).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Aaaaaaaaaaaaaaaaaaaah

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For messages being sent over federation, messages are grouped into EDUs by destination server. We now generate a new message id for each EDU at line 268:

synapse/synapse/handlers/devicemessage.py

Line 268 in 76d44db

message_id = random_string(16)

}
for device_id, message_content in by_device.items()
}
Expand All @@ -267,7 +263,11 @@ async def send_device_message(

remote_edu_contents = {}
for destination, messages in remote_messages.items():
log_kv({"destination": destination})
# The EDU contains a "message_id" property which is used for
# idempotence. Make up a random one.
message_id = random_string(16)
log_kv({"destination": destination, "message_id": message_id})

remote_edu_contents[destination] = {
"messages": messages,
"sender": sender_user_id,
Expand Down
7 changes: 0 additions & 7 deletions synapse/handlers/sync.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1602,13 +1602,6 @@ async def _generate_sync_entry_for_to_device(
user_id, device_id, since_stream_id, now_token.to_device_key
)

for message in messages:
# We pop here as we shouldn't be sending the message ID down
# `/sync`
message_id = message.pop("message_id", None)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This does mean that we'll send down message_id for "old" to-device messages, but I guess that those will drain quickly and so is fine.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, that's a detail I'm brushing under the carpet.

if message_id:
set_tag(SynapseTags.TO_DEVICE_MESSAGE_ID, message_id)

logger.debug(
"Returning %d to-device messages between %d and %d (current token: %d)",
len(messages),
Expand Down