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
This commit is contained in:
Andy Balaam
2026-01-27 13:09:57 +00:00
committed by Andy Balaam
parent 225644111c
commit 8932869423
7 changed files with 76 additions and 19 deletions
+2 -1
View File
@@ -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
@@ -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<Session> {
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,
@@ -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<ToDeviceEncryptedEventContent>)> {
) -> OlmResult<(Session, Raw<ToDeviceEncryptedEventContent>, 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<ToDeviceEncryptedEventContent>)> {
) -> OlmResult<(Session, Raw<ToDeviceEncryptedEventContent>, 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,
@@ -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();
@@ -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.");
@@ -952,7 +952,10 @@ async fn encrypt_content_for_devices(
event_type: String,
bundle_data: impl Serialize,
) -> OlmResult<(Session, Raw<ToDeviceEncryptedEventContent>)> {
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| {
@@ -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();