From 97959bbcd0106b7bb20d6b025c20e60a79f5d1de Mon Sep 17 00:00:00 2001 From: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> Date: Fri, 22 Mar 2024 09:43:35 +0000 Subject: [PATCH] crypto: Log details about olm session after encryption/decryption (#3242) --- Cargo.lock | 38 +++++++++---------- Cargo.toml | 2 +- crates/matrix-sdk-crypto/CHANGELOG.md | 3 ++ .../src/identities/device.rs | 2 - crates/matrix-sdk-crypto/src/olm/account.rs | 6 +-- crates/matrix-sdk-crypto/src/olm/session.rs | 11 ++---- 6 files changed, 27 insertions(+), 35 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 880825f6c..1e43acae6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -41,9 +41,9 @@ dependencies = [ [[package]] name = "aes" -version = "0.8.3" +version = "0.8.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ac1f845298e95f983ff1944b728ae08b8cebab80d684f0a832ed0fc74dfa27e2" +checksum = "b169f7a6d4742236a0a00c541b845991d0ac43e546831af1249753ab4c3aa3a0" dependencies = [ "cfg-if", "cipher", @@ -465,6 +465,12 @@ version = "0.21.7" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9d297deb1925b89f2ccc13d7635fa0714f12c87adce1c75356b39ca9b7178567" +[[package]] +name = "base64" +version = "0.22.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9475866fec1451be56a3c2400fd081ff546538961565ccb5b7142cbd22bc7a51" + [[package]] name = "base64ct" version = "1.6.0" @@ -2563,15 +2569,6 @@ dependencies = [ "either", ] -[[package]] -name = "itertools" -version = "0.11.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b1c173a5686ce8bfa551b3563d0c2170bf24ca44da99c7ca4bfdab5418c3fe57" -dependencies = [ - "either", -] - [[package]] name = "itertools" version = "0.12.1" @@ -4339,7 +4336,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "efb6c9a1dd1def8e2124d17e83a20af56f1570d6c2d2bd9e266ccb768df3840e" dependencies = [ "anyhow", - "itertools 0.11.0", + "itertools 0.10.5", "proc-macro2", "quote", "syn 2.0.48", @@ -5117,9 +5114,9 @@ dependencies = [ [[package]] name = "serde" -version = "1.0.196" +version = "1.0.197" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "870026e60fa08c69f064aa766c10f10b1d62db9ccd4d0abb206472bee0ce3b32" +checksum = "3fb1c873e1b9b056a4dc4c0c198b24c3ffa059243875552b2bd0933b1aee4ce2" dependencies = [ "serde_derive", ] @@ -5146,9 +5143,9 @@ dependencies = [ [[package]] name = "serde_derive" -version = "1.0.196" +version = "1.0.197" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "33c85360c95e7d137454dc81d9a4ed2b8efd8fbe19cee57357b32b9771fccb67" +checksum = "7eb0b34b42edc17f6b7cac84a52a1c5f0e1bb2227e997ca9011ea3dd34e8610b" dependencies = [ "proc-macro2", "quote", @@ -5181,9 +5178,9 @@ dependencies = [ [[package]] name = "serde_json" -version = "1.0.113" +version = "1.0.114" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "69801b70b1c3dac963ecb03a364ba0ceda9cf60c71cfe475e99864759c8b8a79" +checksum = "c5f09b1bd632ef549eaa9f60a1f8de742bdbc698e6cee2095fc84dde5f549ae0" dependencies = [ "indexmap 2.2.2", "itoa", @@ -6345,12 +6342,11 @@ checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" [[package]] name = "vodozemac" version = "0.5.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2790dffeecc522299d72d9a855c43adb0c23ba1dc1112d79a651fdf3beb2a356" +source = "git+https://github.com/matrix-org/vodozemac?rev=0c75746fc8a5eda4a0e490d345d1798b4c6cbd67#0c75746fc8a5eda4a0e490d345d1798b4c6cbd67" dependencies = [ "aes", "arrayvec", - "base64 0.21.7", + "base64 0.22.0", "cbc", "curve25519-dalek", "ed25519-dalek", diff --git a/Cargo.toml b/Cargo.toml index 012944bb7..52d42de64 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -62,7 +62,7 @@ tracing = { version = "0.1.40", default-features = false, features = ["std"] } tracing-core = "0.1.32" uniffi = { git = "https://github.com/mozilla/uniffi-rs", rev = "789a9023b522562a95618443cee5a0d4f111c4c7" } uniffi_bindgen = { git = "https://github.com/mozilla/uniffi-rs", rev = "789a9023b522562a95618443cee5a0d4f111c4c7" } -vodozemac = "0.5.1" +vodozemac = { git="https://github.com/matrix-org/vodozemac", rev = "0c75746fc8a5eda4a0e490d345d1798b4c6cbd67" } wiremock = "0.5.21" zeroize = "1.6.0" diff --git a/crates/matrix-sdk-crypto/CHANGELOG.md b/crates/matrix-sdk-crypto/CHANGELOG.md index 7e3b3abfe..c51e85b21 100644 --- a/crates/matrix-sdk-crypto/CHANGELOG.md +++ b/crates/matrix-sdk-crypto/CHANGELOG.md @@ -19,6 +19,9 @@ Breaking changes: Additions: +- Log more details about the Olm session after encryption and decryption. + ([#3242](https://github.com/matrix-org/matrix-rust-sdk/pull/3242)) + - When Olm message decryption fails, report the error code(s) from the failure. ([#3212](https://github.com/matrix-org/matrix-rust-sdk/pull/3212)) diff --git a/crates/matrix-sdk-crypto/src/identities/device.rs b/crates/matrix-sdk-crypto/src/identities/device.rs index 37b578354..7bd8dbef1 100644 --- a/crates/matrix-sdk-crypto/src/identities/device.rs +++ b/crates/matrix-sdk-crypto/src/identities/device.rs @@ -790,7 +790,6 @@ impl ReadOnlyDevice { recipient_device = ?self.device_id(), recipient_key = ?self.curve25519_key(), event_type, - session, message_id, )) ] @@ -818,7 +817,6 @@ impl ReadOnlyDevice { if let Some(mut session) = session { let message = session.encrypt(self, event_type, content, message_id).await?; - trace!("Successfully encrypted an event"); Ok((session, message)) } else { trace!("Trying to encrypt an event for a device, but no Olm session is found."); diff --git a/crates/matrix-sdk-crypto/src/olm/account.rs b/crates/matrix-sdk-crypto/src/olm/account.rs index 036367d2d..b117a0760 100644 --- a/crates/matrix-sdk-crypto/src/olm/account.rs +++ b/crates/matrix-sdk-crypto/src/olm/account.rs @@ -1026,15 +1026,13 @@ impl Account { message: &PreKeyMessage, ) -> Result { Span::current().record("session_id", debug(message.session_id())); - debug!("Creating a new Olm session from a pre-key message"); + trace!("Creating a new Olm session from a pre-key message"); let result = self.inner.create_inbound_session(their_identity_key, message)?; let now = SecondsSinceUnixEpoch::now(); let session_id = result.session.session_id(); - Span::current().record("session", debug(&result.session)); - - trace!("Olm session created successfully"); + debug!(session=?result.session, "Decrypted an Olm message from a new Olm session"); let session = Session { user_id: self.static_data.user_id.clone(), diff --git a/crates/matrix-sdk-crypto/src/olm/session.rs b/crates/matrix-sdk-crypto/src/olm/session.rs index 99d6b4445..d6497c701 100644 --- a/crates/matrix-sdk-crypto/src/olm/session.rs +++ b/crates/matrix-sdk-crypto/src/olm/session.rs @@ -18,7 +18,7 @@ use ruma::{serde::Raw, OwnedDeviceId, OwnedUserId, SecondsSinceUnixEpoch}; use serde::{Deserialize, Serialize}; use serde_json::json; use tokio::sync::Mutex; -use tracing::{field::debug, trace, Span}; +use tracing::{debug, Span}; use vodozemac::{ olm::{DecryptionError, OlmMessage, Session as InnerSession, SessionConfig, SessionPickle}, Curve25519PublicKey, @@ -81,11 +81,10 @@ impl Session { /// * `message` - The Olm message that should be decrypted. pub async fn decrypt(&mut self, message: &OlmMessage) -> Result { let mut inner = self.inner.lock().await; - Span::current().record("session", debug(&inner)).record("session_id", inner.session_id()); + Span::current().record("session_id", inner.session_id()); let plaintext = inner.decrypt(message)?; - - trace!("Decrypted a Olm message"); + debug!(session=?inner, "Decrypted an Olm message"); let plaintext = String::from_utf8_lossy(&plaintext).to_string(); @@ -126,11 +125,9 @@ impl Session { /// * `plaintext` - The plaintext that should be encrypted. pub(crate) async fn encrypt_helper(&mut self, plaintext: &str) -> OlmMessage { let mut session = self.inner.lock().await; - - Span::current().record("session", debug(&session)); let message = session.encrypt(plaintext); - self.last_use_time = SecondsSinceUnixEpoch::now(); + debug!(?session, "Successfully encrypted an event"); message }