Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(utd_hook): Fix regression causing retry to report false late decrypt #4252

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 15 additions & 9 deletions crates/matrix-sdk-ui/src/timeline/controller/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1064,16 +1064,22 @@ impl<P: RoomDataProvider> TimelineController<P> {

match decryptor.decrypt_event_impl(original_json).await {
Ok(event) => {
trace!(
"Successfully decrypted event that previously failed to decrypt"
);

// Notify observers that we managed to eventually decrypt an event.
if let Some(hook) = unable_to_decrypt_hook {
hook.on_late_decrypt(&remote_event.event_id, *utd_cause).await;
if let matrix_sdk::deserialized_responses::TimelineEventKind::UnableToDecrypt { utd_info, ..} = event.kind {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: use use, not the fully qualified name here

info!("Failed to decrypt event after receiving room key: {:?}", utd_info.reason);
None
} else {
trace!(
kind = ?event.kind,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is probably a bit verbose?

Copy link
Member Author

@BillCarsonFr BillCarsonFr Nov 15, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not changed by this PR. Any other reason to remove it? is it spamming the RS?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Contains most of the event's data that's not privacy-sensitive, so it will be spammy. This line can be reached multiple times for each undecrypted event that failed to re-decrypt again, so it will be super spammy, please remove it.

"Successfully decrypted event that previously failed to decrypt"
);

// Notify observers that we managed to eventually decrypt an event.
if let Some(hook) = unable_to_decrypt_hook {
hook.on_late_decrypt(&remote_event.event_id, *utd_cause).await;
}

Some(event)
}

Some(event)
}
Err(e) => {
info!("Failed to decrypt event after receiving room key: {e}");
Expand Down
90 changes: 79 additions & 11 deletions crates/matrix-sdk-ui/src/timeline/tests/encryption.rs
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ use std::{
io::Cursor,
iter,
sync::{Arc, Mutex},
time::Duration,
};

use as_variant::as_variant;
Expand All @@ -43,13 +44,25 @@ use ruma::{
};
use serde_json::{json, value::to_raw_value};
use stream_assert::assert_next_matches;
use tokio::time::sleep;

use super::TestTimeline;
use crate::{
timeline::{EncryptedMessage, TimelineDetails, TimelineItemContent},
unable_to_decrypt_hook::{UnableToDecryptHook, UnableToDecryptInfo, UtdHookManager},
};

#[derive(Debug, Default)]
struct DummyUtdHook {
utds: Mutex<Vec<UnableToDecryptInfo>>,
}

impl UnableToDecryptHook for DummyUtdHook {
fn on_utd(&self, info: UnableToDecryptInfo) {
self.utds.lock().unwrap().push(info);
}
}

#[async_test]
async fn test_retry_message_decryption() {
const SESSION_ID: &str = "gM8i47Xhu0q52xLfgUXzanCMpLinoyVyH7R58cBuVBU";
Expand All @@ -67,17 +80,6 @@ async fn test_retry_message_decryption() {
HztoSJUr/2Y\n\
-----END MEGOLM SESSION DATA-----";

#[derive(Debug, Default)]
struct DummyUtdHook {
utds: Mutex<Vec<UnableToDecryptInfo>>,
}

impl UnableToDecryptHook for DummyUtdHook {
fn on_utd(&self, info: UnableToDecryptInfo) {
self.utds.lock().unwrap().push(info);
}
}

let hook = Arc::new(DummyUtdHook::default());
let client = test_client_builder(None).build().await.unwrap();
let utd_hook = Arc::new(UtdHookManager::new(hook.clone(), client));
Expand Down Expand Up @@ -170,6 +172,72 @@ async fn test_retry_message_decryption() {
}
}

// There has been a regression when the `retry_event_decryption` function
// changed from failing with an Error to instead return a new type of timeline
// event in UTD. The regression caused the timeline to consider any
// re-decryption attempt as successful.
#[async_test]
async fn test_false_positive_late_decryption_regression() {
const SESSION_ID: &str = "gM8i47Xhu0q52xLfgUXzanCMpLinoyVyH7R58cBuVBU";

let hook = Arc::new(DummyUtdHook::default());
let client = test_client_builder(None).build().await.unwrap();
let utd_hook =
Arc::new(UtdHookManager::new(hook.clone(), client).with_max_delay(Duration::from_secs(1)));

let timeline = TestTimeline::with_unable_to_decrypt_hook(utd_hook.clone());

let f = &timeline.factory;
timeline
.handle_live_event(
f.event(RoomEncryptedEventContent::new(
EncryptedEventScheme::MegolmV1AesSha2(
MegolmV1AesSha2ContentInit {
ciphertext: "\
AwgAEtABPRMavuZMDJrPo6pGQP4qVmpcuapuXtzKXJyi3YpEsjSWdzuRKIgJzD4P\
cSqJM1A8kzxecTQNJsC5q22+KSFEPxPnI4ltpm7GFowSoPSW9+bFdnlfUzEP1jPq\
YevHAsMJp2fRKkzQQbPordrUk1gNqEpGl4BYFeRqKl9GPdKFwy45huvQCLNNueql\
CFZVoYMuhxrfyMiJJAVNTofkr2um2mKjDTlajHtr39pTG8k0eOjSXkLOSdZvNOMz\
hGhSaFNeERSA2G2YbeknOvU7MvjiO0AKuxaAe1CaVhAI14FCgzrJ8g0y5nly+n7x\
QzL2G2Dn8EoXM5Iqj8W99iokQoVsSrUEnaQ1WnSIfewvDDt4LCaD/w7PGETMCQ"
.to_owned(),
sender_key: "DeHIg4gwhClxzFYcmNntPNF9YtsdZbmMy8+3kzCMXHA".to_owned(),
device_id: "NLAZCWIOCO".into(),
session_id: SESSION_ID.into(),
}
.into(),
),
None,
))
.sender(&BOB)
.into_utd_sync_timeline_event(),
)
.await;

let own_user_id = user_id!("@example:morheus.localhost");
let olm_machine = OlmMachine::new(own_user_id, "SomeDeviceId".into()).await;

timeline
.controller
.retry_event_decryption_test(
room_id!("!DovneieKSTkdHKpIXy:morpheus.localhost"),
olm_machine,
Some(iter::once(SESSION_ID.to_owned()).collect()),
)
.await;
assert_eq!(timeline.controller.items().await.len(), 2);

// Wait past the max delay for utd late decryption detection
sleep(Duration::from_secs(2)).await;

{
let utds = hook.utds.lock().unwrap();
assert_eq!(utds.len(), 1);
// Without the regression fix this would be Some(time to decrypt)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// Without the regression fix this would be Some(time to decrypt)
// This is the main thing we're testing: if this wasn't identified as a definite UTD, this would be `Some(..)`.

assert!(utds[0].time_to_decrypt.is_none());
}
}

#[async_test]
async fn test_retry_edit_decryption() {
const SESSION1_KEY: &[u8] = b"\
Expand Down
14 changes: 10 additions & 4 deletions crates/matrix-sdk-ui/src/timeline/traits.rs
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ use eyeball::Subscriber;
use futures_util::FutureExt as _;
use indexmap::IndexMap;
#[cfg(test)]
use matrix_sdk::crypto::{DecryptionSettings, TrustRequirement};
use matrix_sdk::crypto::{DecryptionSettings, RoomEventDecryptionResult, TrustRequirement};
use matrix_sdk::{
deserialized_responses::TimelineEvent, event_cache::paginator::PaginableRoom, BoxFuture,
Result, Room,
Expand Down Expand Up @@ -302,8 +302,14 @@ impl Decryptor for (matrix_sdk_base::crypto::OlmMachine, ruma::OwnedRoomId) {
let (olm_machine, room_id) = self;
let decryption_settings =
DecryptionSettings { sender_device_trust_requirement: TrustRequirement::Untrusted };
let event =
olm_machine.decrypt_room_event(raw.cast_ref(), room_id, &decryption_settings).await?;
Ok(event.into())
match olm_machine
.try_decrypt_room_event(raw.cast_ref(), room_id, &decryption_settings)
.await?
{
RoomEventDecryptionResult::Decrypted(decrypted) => Ok(decrypted.into()),
RoomEventDecryptionResult::UnableToDecrypt(utd_info) => {
Ok(TimelineEvent::new_utd_event(raw.clone(), utd_info))
}
}
Comment on lines +305 to +313
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is this change needed, out of curiosity? This is for the test timeline; is it operating that differently from the non-test timeline?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's needed to make the regression test ~"fails correctly".
If not the test never detects the behavior change because it is using the mock Decryptor that continues to fail with an error when there is an UTD instead of return a OK UTDEvent type.

The underlying problem is that we use a big catch everything Error for all possible errors of the SDK. And here the change that created the regression should have resulted in a change of signature of the trait. It is not anymore Result<, ALLERRORS> but a Result <,SubsetOfErrors>?

}
}
Loading