rpc: add logging to correlate Matrix event ID to signald request ID

mausignald/rpc.py

@@ -198,7 +198,8 @@ class SignaldRPCClient:
     ) -> tuple[asyncio.Future, dict[str, Any]]:
         req_id = req_id or uuid4()
         req = {"id": str(req_id), "type": command, **data}
-        self.log.trace("Request %s: %s %s", req_id, command, data)
+        self.log.debug("Request %s: %s", req_id, command)
+        self.log.trace("Request %s: %s with data: %s", req_id, command, data)
         return self._wait_response(req_id), req
 
     def _wait_response(self, req_id: UUID) -> asyncio.Future:

mausignald/signald.py

@@ -172,11 +172,18 @@ class SignaldClient(SignaldRPCClient):
             field_name = "group" if simple_name else "recipientGroupId"
         return {field_name: recipient}
 
-    async def react(self, username: str, recipient: Address | GroupID, reaction: Reaction) -> None:
+    async def react(
+        self,
+        username: str,
+        recipient: Address | GroupID,
+        reaction: Reaction,
+        req_id: UUID | None = None,
+    ) -> None:
         await self.request_v1(
             "react",
             username=username,
             reaction=reaction.serialize(),
+            req_id=req_id,
             **self._recipient_to_args(recipient),
         )
 
@@ -199,6 +206,7 @@ class SignaldClient(SignaldRPCClient):
         attachments: list[Attachment] | None = None,
         mentions: list[Mention] | None = None,
         timestamp: int | None = None,
+        req_id: UUID | None = None,
     ) -> None:
         serialized_quote = quote.serialize() if quote else None
         serialized_attachments = [attachment.serialize() for attachment in (attachments or [])]
@@ -211,6 +219,7 @@ class SignaldClient(SignaldRPCClient):
             quote=serialized_quote,
             mentions=serialized_mentions,
             timestamp=timestamp,
+            req_id=req_id,
             **self._recipient_to_args(recipient),
         )
 

mautrix_signal/portal.py

@@ -438,8 +438,11 @@ class Portal(DBPortal, BasePortal):
         retry_message_event_id = None
         for retry_num in range(retry_count):
             try:
-                self.log.info(f"Send attempt {retry_num}")
-                await send_fn(sender, event_id, **send_args)
+                req_id = uuid4()
+                self.log.info(
+                    f"Send attempt {retry_num}. Attempting to send {event_id} with {req_id}"
+                )
+                await send_fn(sender, event_id, req_id=req_id, **send_args)
 
                 # It was successful.
                 if retry_message_event_id is not None:
@@ -529,7 +532,12 @@ class Portal(DBPortal, BasePortal):
             await self._send_delivery_receipt(event_id)
 
     async def _handle_matrix_reaction(
-        self, sender: u.User, event_id: EventID, reacting_to: EventID, emoji: str
+        self,
+        sender: u.User,
+        event_id: EventID,
+        reacting_to: EventID,
+        emoji: str,
+        req_id: UUID | None = None,
     ) -> None:
         message = await DBMessage.get_by_mxid(reacting_to, self.mxid)
         if not message:
@@ -552,7 +560,9 @@ class Portal(DBPortal, BasePortal):
                 target_sent_timestamp=message.timestamp,
             )
             self.log.trace(f"{sender.mxid} reacted to {message.timestamp} with {emoji}")
-            await self.signal.react(sender.username, recipient=self.chat_id, reaction=reaction)
+            await self.signal.react(
+                sender.username, recipient=self.chat_id, reaction=reaction, req_id=req_id
+            )
 
         await self._upsert_reaction(existing, self.main_intent, event_id, sender, message, emoji)