From 89328694238464440059545731f88ffcaaaee3b5 Mon Sep 17 00:00:00 2001 From: Andy Balaam Date: Tue, 27 Jan 2026 13:09:57 +0000 Subject: [PATCH] Log more information about gossip requests So we can track which `m.secret.send` messages were successfully sent or retried, and which secrets were contained in them. Part of #6058 --- crates/matrix-sdk-crypto/CHANGELOG.md | 3 +- .../src/gossiping/machine.rs | 44 +++++++++++++++++-- .../src/identities/device.rs | 36 ++++++++++----- .../src/machine/test_helpers.rs | 2 +- .../src/machine/tests/olm_encryption.rs | 2 +- .../src/session_manager/group_sessions/mod.rs | 5 ++- .../src/session_manager/sessions.rs | 3 +- 7 files changed, 76 insertions(+), 19 deletions(-) diff --git a/crates/matrix-sdk-crypto/CHANGELOG.md b/crates/matrix-sdk-crypto/CHANGELOG.md index d82a8c41d..9ecb961ff 100644 --- a/crates/matrix-sdk-crypto/CHANGELOG.md +++ b/crates/matrix-sdk-crypto/CHANGELOG.md @@ -8,6 +8,8 @@ All notable changes to this project will be documented in this file. ### Features +- Improved logging when we are sending secrets in `GossipMachine`. + ([#6074](https://github.com/matrix-org/matrix-rust-sdk/pull/6074)) - Added a new field `forwarder` to `InboundGroupSession` of type `ForwarderData`, which stores information about the forwarder of a session shared in a room key bundle under [MSC4268](https://github.com/matrix-org/matrix-spec-proposals/pull/4268). ([#5980])(https://github.com/matrix-org/matrix-rust-sdk/pull/5980) - The `OutboundGroupSession` and `OlmMachine` now return the `EncryptionInfo` @@ -20,7 +22,6 @@ All notable changes to this project will be documented in this file. ([#6017](https://github.com/matrix-org/matrix-rust-sdk/pull/6017)) ([#6044](https://github.com/matrix-org/matrix-rust-sdk/pull/6044)) - ### Refactor - [**breaking**] The `message-ids` feature has been removed. It was already a no-op and has now diff --git a/crates/matrix-sdk-crypto/src/gossiping/machine.rs b/crates/matrix-sdk-crypto/src/gossiping/machine.rs index 061bea993..372f1860f 100644 --- a/crates/matrix-sdk-crypto/src/gossiping/machine.rs +++ b/crates/matrix-sdk-crypto/src/gossiping/machine.rs @@ -323,7 +323,7 @@ impl GossipMachine { "Sharing a secret with a device", ); - match self.share_secret(&device, content).await { + match self.share_secret(&device, content, secret_name).await { Ok(s) => Ok(Some(s)), Err(OlmError::MissingSession) => { info!( @@ -534,13 +534,22 @@ impl GossipMachine { } } + /// Add an `m.secret.send` request to the `outgoing_requests` queue. + /// + /// # Arguments + /// + /// * `device` is the device to send the request to. + /// * `content` is the actual event content, containing the secret to send. + /// * `secret_name` is the name of the secret e.g. `m.megolm_backup.v1` + /// (used for logging). async fn share_secret( &self, device: &Device, content: SecretSendContent, + secret_name: &SecretName, ) -> OlmResult { let event_type = content.event_type().to_owned(); - let (used_session, content) = device.encrypt(&event_type, content).await?; + let (used_session, content, message_id) = device.encrypt(&event_type, content).await?; let encrypted_event_type = content.event_type().to_owned(); @@ -555,6 +564,16 @@ impl GossipMachine { request_id: request.txn_id.clone(), request: Arc::new(request.into()), }; + + debug!( + recipient = ?device.user_id(), + event_type, + request_id = ?request.request_id, + ?secret_name, + ?message_id, + "Creating outgoing `m.secret.send` to-device request" + ); + self.inner.outgoing_requests.write().insert(request.request_id.clone(), request); Ok(used_session) @@ -583,6 +602,15 @@ impl GossipMachine { request_id: request.txn_id.clone(), request: Arc::new(request.into()), }; + + debug!( + recipient = ?device.user_id(), + event_type = event_type, + request_id = ?request.request_id, + session_id = session.session_id(), + "Creating outgoing `m.forwarded_room_key` to-device request" + ); + self.inner.outgoing_requests.write().insert(request.request_id.clone(), request); Ok(used_session) @@ -816,7 +844,7 @@ impl GossipMachine { let info = self.inner.store.get_outgoing_secret_requests(id).await?; if let Some(mut info) = info { - trace!( + debug!( recipient = ?info.request_recipient, request_type = info.request_type(), request_id = ?info.request_id, @@ -824,6 +852,14 @@ impl GossipMachine { ); info.sent_out = true; self.save_outgoing_key_info(info).await?; + } else if let Some(req) = self.inner.outgoing_requests.read().get(id) { + // This outgoing event was not saved into the store. This is + // expected: for example `m.secret.send` events are only stored in + // `outgoing_requests`, not in the store. + debug!( + request_id = ?req.request_id, + "Marking outgoing request as sent" + ); } self.inner.outgoing_requests.write().remove(id); @@ -835,7 +871,7 @@ impl GossipMachine { /// /// This will queue up a request cancellation. async fn mark_as_done(&self, key_info: &GossipRequest) -> Result<(), CryptoStoreError> { - trace!( + debug!( recipient = ?key_info.request_recipient, request_type = key_info.request_type(), request_id = ?key_info.request_id, diff --git a/crates/matrix-sdk-crypto/src/identities/device.rs b/crates/matrix-sdk-crypto/src/identities/device.rs index 57b153a46..84543b749 100644 --- a/crates/matrix-sdk-crypto/src/identities/device.rs +++ b/crates/matrix-sdk-crypto/src/identities/device.rs @@ -412,12 +412,23 @@ impl Device { /// /// # Arguments /// + /// * `event_type` - The type of the event that should be encrypted. /// * `content` - The content of the event that should be encrypted. + /// + /// # Returns + /// + /// On success, a tuple `(session, content, message_id)`, where `session` is + /// the Olm [`Session`] that was used to encrypt the content, `content` + /// is the content for the `m.room.encrypted` to-device event, and + /// `message_id` is the newly-minted message ID stored within the content. + /// + /// If an Olm session has not already been established with this device, + /// returns `Err(OlmError::MissingSession)`. pub(crate) async fn encrypt( &self, event_type: &str, content: impl Serialize, - ) -> OlmResult<(Session, Raw)> { + ) -> OlmResult<(Session, Raw, String)> { self.inner.encrypt(self.verification_machine.store.inner(), event_type, content).await } @@ -440,7 +451,9 @@ impl Device { let event_type = content.event_type().to_owned(); - self.encrypt(&event_type, content).await + self.encrypt(&event_type, content) + .await + .map(|(session, message, _message_id)| (session, message)) } /// Encrypt an event for this device. @@ -486,7 +499,7 @@ impl Device { return Err(OlmError::Withheld(withheld_code)); } - let (used_session, raw_encrypted) = self.encrypt(event_type, content).await?; + let (used_session, raw_encrypted, _message_id) = self.encrypt(event_type, content).await?; // Persist the used session self.verification_machine @@ -798,9 +811,10 @@ impl DeviceData { /// /// # Returns /// - /// On success, a tuple `(session, content)`, where `session` is the Olm - /// [`Session`] that was used to encrypt the content, and `content` is - /// the content for the `m.room.encrypted` to-device event. + /// On success, a tuple `(session, content, message_id)`, where `session` is + /// the Olm [`Session`] that was used to encrypt the content, `content` + /// is the content for the `m.room.encrypted` to-device event, and + /// `message_id` is the newly-minted message ID stored within the content. /// /// If an Olm session has not already been established with this device, /// returns `Err(OlmError::MissingSession)`. @@ -819,7 +833,7 @@ impl DeviceData { store: &CryptoStoreWrapper, event_type: &str, content: impl Serialize, - ) -> OlmResult<(Session, Raw)> { + ) -> OlmResult<(Session, Raw, String)> { #[cfg(not(target_family = "wasm"))] let message_id = ulid::Ulid::new().to_string(); #[cfg(target_family = "wasm")] @@ -830,8 +844,10 @@ impl DeviceData { let session = self.get_most_recent_session(store).await?; if let Some(mut session) = session { - let message = session.encrypt(self, event_type, content, Some(message_id)).await?; - Ok((session, message)) + let message = + session.encrypt(self, event_type, content, Some(message_id.clone())).await?; + + Ok((session, message, message_id)) } else { trace!("Trying to encrypt an event for a device, but no Olm session is found."); Err(OlmError::MissingSession) @@ -848,7 +864,7 @@ impl DeviceData { let event_type = content.event_type().to_owned(); match self.encrypt(store, &event_type, content).await { - Ok((session, encrypted)) => Ok(MaybeEncryptedRoomKey::Encrypted { + Ok((session, encrypted, _)) => Ok(MaybeEncryptedRoomKey::Encrypted { share_info: Box::new(ShareInfo::new_shared( session.sender_key().to_owned(), message_index, diff --git a/crates/matrix-sdk-crypto/src/machine/test_helpers.rs b/crates/matrix-sdk-crypto/src/machine/test_helpers.rs index b85c90835..a159437da 100644 --- a/crates/matrix-sdk-crypto/src/machine/test_helpers.rs +++ b/crates/matrix-sdk-crypto/src/machine/test_helpers.rs @@ -320,7 +320,7 @@ pub async fn get_machine_pair_with_setup_sessions_test_helper( let bob_device = alice.get_device(bob.user_id(), bob.device_id(), None).await.unwrap().unwrap(); - let (session, content) = + let (session, content, _) = bob_device.encrypt("m.dummy", ToDeviceDummyEventContent::new()).await.unwrap(); alice.store().save_sessions(&[session]).await.unwrap(); diff --git a/crates/matrix-sdk-crypto/src/machine/tests/olm_encryption.rs b/crates/matrix-sdk-crypto/src/machine/tests/olm_encryption.rs index e45a9e8f1..853f1c64b 100644 --- a/crates/matrix-sdk-crypto/src/machine/tests/olm_encryption.rs +++ b/crates/matrix-sdk-crypto/src/machine/tests/olm_encryption.rs @@ -203,7 +203,7 @@ async fn olm_encryption_test_helper(use_fallback_key: bool) { let bob_device = alice.get_device(bob.user_id(), bob.device_id(), None).await.unwrap().unwrap(); - let (_, content) = bob_device + let (_, content, _) = bob_device .encrypt("m.dummy", ToDeviceDummyEventContent::new()) .await .expect("We should be able to encrypt a dummy event."); diff --git a/crates/matrix-sdk-crypto/src/session_manager/group_sessions/mod.rs b/crates/matrix-sdk-crypto/src/session_manager/group_sessions/mod.rs index 600bc6a3c..16f36152c 100644 --- a/crates/matrix-sdk-crypto/src/session_manager/group_sessions/mod.rs +++ b/crates/matrix-sdk-crypto/src/session_manager/group_sessions/mod.rs @@ -952,7 +952,10 @@ async fn encrypt_content_for_devices( event_type: String, bundle_data: impl Serialize, ) -> OlmResult<(Session, Raw)> { - device.encrypt(store.as_ref(), &event_type, bundle_data).await + device + .encrypt(store.as_ref(), &event_type, bundle_data) + .await + .map(|(session, message, _message_id)| (session, message)) } let tasks = devices.iter().map(|device| { diff --git a/crates/matrix-sdk-crypto/src/session_manager/sessions.rs b/crates/matrix-sdk-crypto/src/session_manager/sessions.rs index 62a6bf55b..2cd3b413f 100644 --- a/crates/matrix-sdk-crypto/src/session_manager/sessions.rs +++ b/crates/matrix-sdk-crypto/src/session_manager/sessions.rs @@ -151,7 +151,8 @@ impl SessionManager { if self.wedged_devices.write().get_mut(user_id).is_some_and(|d| d.remove(device_id)) && let Some(device) = self.store.get_device(user_id, device_id).await? { - let (_, content) = device.encrypt("m.dummy", ToDeviceDummyEventContent::new()).await?; + let (_, content, _) = + device.encrypt("m.dummy", ToDeviceDummyEventContent::new()).await?; let event_type = content.event_type().to_owned();