From f58f3fe055265fe290c01beecfd972fec9df3781 Mon Sep 17 00:00:00 2001
From: Jonas Platte <jplatte@matrix.org>
Date: Wed, 21 Dec 2022 16:56:34 +0100
Subject: [PATCH] chore(sdk): Add more logging to decryption retrying

---
 crates/matrix-sdk/src/room/timeline/inner.rs |  9 +++++++++
 crates/matrix-sdk/src/room/timeline/mod.rs   | 10 +++++++++-
 2 files changed, 18 insertions(+), 1 deletion(-)

diff --git a/crates/matrix-sdk/src/room/timeline/inner.rs b/crates/matrix-sdk/src/room/timeline/inner.rs
index 7731efced..947eb200a 100644
--- a/crates/matrix-sdk/src/room/timeline/inner.rs
+++ b/crates/matrix-sdk/src/room/timeline/inner.rs
@@ -12,6 +12,8 @@ use ruma::{
     MilliSecondsSinceUnixEpoch, OwnedEventId, OwnedTransactionId, RoomId, TransactionId, UserId,
 };
 use tracing::{error, info, warn};
+#[cfg(feature = "e2e-encryption")]
+use tracing::{instrument, trace};
 
 use super::{
     event_handler::{
@@ -149,6 +151,7 @@ impl TimelineInner {
     }
 
     #[cfg(feature = "e2e-encryption")]
+    #[instrument(skip(self, olm_machine, own_user_id))]
     pub(super) async fn retry_event_decryption(
         &self,
         room_id: &RoomId,
@@ -190,6 +193,7 @@ impl TimelineInner {
             .collect();
 
         if utds_for_session.is_empty() {
+            trace!("Found no events to retry decryption for");
             return;
         }
 
@@ -206,6 +210,11 @@ impl TimelineInner {
                 }
             };
 
+            trace!(
+                %event_id, %session_id,
+                "Successfully decrypted event that previously failed to decrypt"
+            );
+
             // Because metadata is always locked before we attempt to lock the
             // items, this will never be contended.
             // Because there is an `.await` in this loop, we have to re-lock
diff --git a/crates/matrix-sdk/src/room/timeline/mod.rs b/crates/matrix-sdk/src/room/timeline/mod.rs
index b6c66b5d0..1919a2c50 100644
--- a/crates/matrix-sdk/src/room/timeline/mod.rs
+++ b/crates/matrix-sdk/src/room/timeline/mod.rs
@@ -29,7 +29,7 @@ use ruma::{
     events::{fully_read::FullyReadEventContent, relation::Annotation, AnyMessageLikeEventContent},
     EventId, OwnedEventId, OwnedUserId, TransactionId, UInt,
 };
-use tracing::{error, instrument};
+use tracing::{debug_span, error, instrument};
 
 use super::{Joined, Room};
 use crate::{
@@ -116,6 +116,7 @@ impl Timeline {
             use std::iter;
 
             use ruma::events::room_key::ToDeviceRoomKeyEvent;
+            use tracing::{trace, Instrument};
 
             use crate::Client;
 
@@ -125,6 +126,12 @@ impl Timeline {
                 let room_id = room_id.clone();
                 async move {
                     if event.content.room_id != room_id {
+                        let event_room_id = &event.content.room_id;
+                        let session_id = &event.content.session_id;
+                        trace!(
+                            %event_room_id, timeline_room_id = %room_id, %session_id,
+                            "Received to-device room key event for a different room, ignoring"
+                        );
                         return;
                     }
 
@@ -148,6 +155,7 @@ impl Timeline {
                         )
                         .await;
                 }
+                .instrument(debug_span!("handle_to_device_room_key_event"))
             }
         });
         #[cfg(feature = "e2e-encryption")]