From f3df7e8c811992faa1fd7fb7e3db830b34538917 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jagoda=20=C5=9Al=C4=85zak?= Date: Fri, 24 Jul 2026 14:26:38 +0200 Subject: [PATCH] test: Assert log warnings and errors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds `assert_warn`, `assert_error` and `assert_many` methods to `TestContext`, that let us assert that a certain warning or error is logged during the test. Also asserts test logs should not contain any other errors or warnings. Adjusts tests accordingly. Signed-off-by: Jagoda Ślązak --- .../automatic_relay_management_tests.rs | 6 + src/calls/calls_tests.rs | 1 + src/chat/chat_tests.rs | 54 ++++- src/configure.rs | 8 + src/contact/contact_tests.rs | 8 +- src/context/context_tests.rs | 5 + src/e2ee.rs | 7 +- src/ephemeral/ephemeral_tests.rs | 18 +- src/events.rs | 12 + src/events/payload.rs | 18 ++ src/imex.rs | 30 ++- src/imex/transfer.rs | 4 + src/log.rs | 4 + src/message/message_tests.rs | 3 +- src/mimefactory/mimefactory_tests.rs | 7 + src/mimeparser/mimeparser_tests.rs | 10 +- .../shared_secret_decryption_tests.rs | 21 +- src/net/http.rs | 2 + src/peer_channels.rs | 3 +- src/qr/qr_tests.rs | 4 + src/receive_imf.rs | 6 +- src/receive_imf/receive_imf_tests.rs | 189 ++++++++++----- src/securejoin/securejoin_tests.rs | 34 ++- src/sql/sql_tests.rs | 2 + src/stats/stats_tests.rs | 16 +- src/summary.rs | 1 + src/sync.rs | 3 + src/test_utils.rs | 223 +++++++++++++----- src/tests/aeap.rs | 5 + src/tests/pre_messages/forward_and_save.rs | 2 +- src/tests/pre_messages/legacy.rs | 2 +- src/tests/pre_messages/receiving.rs | 25 +- src/tests/verified_chats.rs | 8 + src/tools/tools_tests.rs | 1 + src/webxdc/webxdc_tests.rs | 7 +- 35 files changed, 584 insertions(+), 165 deletions(-) diff --git a/src/automatic_relay_management/automatic_relay_management_tests.rs b/src/automatic_relay_management/automatic_relay_management_tests.rs index e92b8d564f..e8ba60b329 100644 --- a/src/automatic_relay_management/automatic_relay_management_tests.rs +++ b/src/automatic_relay_management/automatic_relay_management_tests.rs @@ -275,6 +275,12 @@ async fn test_maybe_add_additional_relays_failure() -> Result<()> { // and we don't want to try all of them in a single call: assert_eq!(load_relay_candidates(t, now).await?.is_empty(), false); + t.assert_many(vec![ + (false, "DNS lookup with memory cache failure", 48), + (false, "Could not find DNS resolutions", 39), + ]) + .await; + Ok(()) } diff --git a/src/calls/calls_tests.rs b/src/calls/calls_tests.rs index c84b21f785..44bc159cf2 100644 --- a/src/calls/calls_tests.rs +++ b/src/calls/calls_tests.rs @@ -679,6 +679,7 @@ async fn test_end_text_call() -> Result<()> { .unwrap(); assert_eq!(received2.msg_ids.len(), 1); assert_eq!(received2.chat_id, DC_CHAT_ID_TRASH); + alice.assert_warn("does not refer to a call message").await; Ok(()) } diff --git a/src/chat/chat_tests.rs b/src/chat/chat_tests.rs index c54e107b9f..add262fe53 100644 --- a/src/chat/chat_tests.rs +++ b/src/chat/chat_tests.rs @@ -309,6 +309,8 @@ async fn test_add_contact_to_chat_ex_add_self() { .await .unwrap(); assert_eq!(added, false); + t.assert_warn("Invalid attempt to add self e-mail address to group") + .await; } /// Test adding and removing members in a group chat. @@ -2714,7 +2716,7 @@ async fn test_resend_doesnt_resort_msg() -> Result<()> { let mut tcm = TestContextManager::new(); let alice = &tcm.alice().await; let bob = &tcm.bob().await; - let alice_grp = create_group(alice, "").await?; + let alice_grp = create_group(alice, "group").await?; let sent1 = alice.send_text(alice_grp, "hi").await; let sent1_ts = Message::load_from_db(alice, sent1.sender_msg_id) .await? @@ -2878,6 +2880,9 @@ async fn test_broadcast_members_cant_see_each_other() -> Result<()> { let parsed_by_bob = bob.parse_msg(&vc_pubkey).await; assert!(parsed_by_bob.decryption_error.is_some()); + bob.assert_warn("Could not find symmetric secret for session key") + .await; + charlie.recv_msg_trash(&vc_pubkey).await; } @@ -2915,6 +2920,8 @@ async fn test_broadcast_members_cant_see_each_other() -> Result<()> { let parsed_by_bob = bob.parse_msg(&member_added).await; assert!(parsed_by_bob.decryption_error.is_some()); + bob.assert_warn("decryption failed: decrypt_the_ring: missing key") + .await; let rcvd = charlie.recv_msg(&member_added).await; assert_eq!(rcvd.param.get_cmd(), SystemMessage::MemberAddedToGroup); @@ -2947,6 +2954,8 @@ async fn test_broadcast_members_cant_see_each_other() -> Result<()> { let parsed_by_bob = bob.parse_msg(&member_removed).await; assert!(parsed_by_bob.decryption_error.is_some()); + bob.assert_warn("decryption failed: decrypt_the_ring: missing key") + .await; let rcvd = charlie.recv_msg(&member_removed).await; assert_eq!(rcvd.param.get_cmd(), SystemMessage::MemberRemovedFromGroup); @@ -3099,6 +3108,9 @@ async fn test_broadcast_resend_to_new_member() -> Result<()> { .is_some() ); bob.recv_msg_trash(&resent_msg).await; + bob.assert_warn("missing key").await; + bob.assert_warn("missing key").await; + bob.assert_warn("unencrypted message").await; } assert!(alice.pop_sent_msg_opt().await.is_none()); Ok(()) @@ -3117,6 +3129,7 @@ async fn test_broadcast_resend_failed_msg_to_new_member() -> Result<()> { let alice_msg_id = alice.send_text(alice_bc_id, "text").await.sender_msg_id; let mut msg = Message::load_from_db(alice, alice_msg_id).await?; message::set_msg_failed(alice, &mut msg, "error").await?; + alice.assert_warn("error").await; let fiona_bc_id = tcm.exec_securejoin_qr(fiona, alice, &qr).await; let resent_msg = alice.pop_sent_msg().await; let fiona_msg = fiona.recv_msg(&resent_msg).await; @@ -3208,6 +3221,7 @@ async fn test_broadcast_recipients_sync1() -> Result<()> { sync(alice1, alice2).await; let a2_chatlist = Chatlist::try_load(alice2, 0, Some("Channel"), None).await?; assert!(a2_chatlist.is_empty()); + alice2.assert_warn("No chat for grpid").await; // Alice1 adds Charlie to the broadcast channel, // and now, Alice2 receives the messages @@ -3223,6 +3237,7 @@ async fn test_broadcast_recipients_sync1() -> Result<()> { let request_with_auth = charlie.pop_sent_msg().await; alice1.recv_msg_trash(&request_with_auth).await; alice2.recv_msg_trash(&request_with_auth).await; + alice2.assert_warn("unknown grpid").await; let member_added = alice1.pop_sent_msg().await; let a2_charlie_added = alice2.recv_msg(&member_added).await; @@ -3549,6 +3564,7 @@ async fn test_chat_description( tcm.section("Check Alice's second device"); alice2.recv_msg(&sent).await; + let alice2_chat_id = get_chat_id_by_grpid( alice2, &Chat::load_from_db(alice, alice_chat_id).await?.grpid, @@ -3935,6 +3951,8 @@ async fn test_leave_broadcast_multidevice() -> Result<()> { tcm.section("Bob's second device also receives these messages"); bob1.recv_msg_trash(&vc_pubkey).await; + bob1.assert_warn("decryption failed").await; + bob1.assert_warn("unencrypted message").await; bob1.recv_msg_trash(&request_with_auth).await; bob1.recv_msg(&member_added).await; @@ -4024,6 +4042,7 @@ async fn test_only_broadcast_owner_can_send_1() -> Result<()> { "Bob receives an answer, but shows it in a single chat because of a fingerprint mismatch", ); let rcvd = bob.recv_msg(&member_added).await; + bob.assert_warn("wrong sender").await; assert_eq!(rcvd.text, "Member bob@example.net was added."); let bob_alice_chat_id = bob.get_chat(alice).await.id; @@ -4088,6 +4107,8 @@ async fn test_only_broadcast_owner_can_send_2() -> Result<()> { tcm.section("Alice sends a message, which is trashed"); let sent = alice.send_text(alice_broadcast_id, "Hi").await; bob.recv_msg_trash(&sent).await; + bob.assert_warn("This sender is not allowed to encrypt with this secret key") + .await; let EventType::Warning(warning) = bob .evtracker .get_matching(|ev| matches!(ev, EventType::Warning(_))) @@ -4201,6 +4222,10 @@ async fn test_encrypt_decrypt_broadcast() -> Result<()> { tcm.section("If Bob doesn't know the secret, he can't decrypt the message"); bob_without_secret.recv_msg_trash(&sent).await; + bob_without_secret + .assert_warn("Could not find symmetric secret for session key") + .await; + bob_without_secret.assert_warn("unencrypted message").await; Ok(()) } @@ -4316,7 +4341,9 @@ async fn test_out_failed_on_all_keys_missing() -> Result<()> { let bob = &tcm.bob().await; let fiona = &tcm.fiona().await; - let bob_chat_id = bob.create_group_with_members("", &[alice, fiona]).await; + let bob_chat_id = bob + .create_group_with_members("group", &[alice, fiona]) + .await; bob.send_text(bob_chat_id, "Gossiping Fiona's key").await; alice .recv_msg(&bob.send_text(bob_chat_id, "No key gossip").await) @@ -4328,6 +4355,8 @@ async fn test_out_failed_on_all_keys_missing() -> Result<()> { let mut msg = Message::new_text("Hi".to_string()); send_msg(alice, alice_chat_id, &mut msg).await.ok(); assert_eq!(msg.id.get_state(alice).await?, MessageState::OutFailed); + alice.assert_warn("Missing key").await; + alice.assert_warn("cannot encrypt").await; Ok(()) } @@ -4948,6 +4977,9 @@ async fn test_sync_broadcast_and_send_message() -> Result<()> { let bob_broadcast_id = tcm .exec_securejoin_qr_multi_device(bob, &[alice1, alice2], &qr) .await; + bob.assert_warn("Could not find symmetric secret for session key") + .await; + bob.assert_warn("unencrypted message").await; let a2b_contact_id = alice2.add_or_lookup_contact_no_key(bob).await.id; assert_eq!( @@ -5119,7 +5151,7 @@ async fn test_blocked_bob_cant_join_chat() -> Result<()> { let alice2_bob_id = alice2.add_or_lookup_contact_id(bob).await; Contact::block(alice2, alice2_bob_id).await?; - let alice1_chat_id = create_group(alice1, "").await?; + let alice1_chat_id = create_group(alice1, "group").await?; sync(alice1, alice2).await; let alice1_chat = Chat::load_from_db(alice1, alice1_chat_id).await?; let (alice2_chat_id, _blocked) = get_chat_id_by_grpid(alice2, &alice1_chat.grpid) @@ -5130,6 +5162,8 @@ async fn test_blocked_bob_cant_join_chat() -> Result<()> { tcm.exec_securejoin_qr_multi_device(bob, &[alice1, alice2], &qr) .await; + alice2.assert_warn("blocked").await; + alice2.assert_warn("blocked").await; let alice1_bob_id = alice1.add_or_lookup_contact_id(bob).await; assert_eq!(get_chat_contacts(alice1, alice1_chat_id).await?.len(), 2); // "vg-member-added" from alice1 adds bob for alice2 to provide membership consistency on @@ -5144,6 +5178,7 @@ async fn test_blocked_bob_cant_join_chat() -> Result<()> { remove_contact_from_chat(alice1, alice1_chat_id, alice1_bob_id).await?; bob.recv_msg(&alice1.pop_sent_msg().await).await; tcm.exec_securejoin_qr(bob, alice1, &qr).await; + alice1.assert_warn("blocked").await; let members = get_chat_contacts(alice1, alice1_chat_id).await?; assert_eq!(members.len(), 1); assert!(members.contains(&ContactId::SELF)); @@ -5174,6 +5209,9 @@ async fn test_blocked_bob_cant_create_single_chat_via_securejoin() -> Result<()> assert_eq!(get_chat_cnt(alice2).await?, chat_cnt); tcm.exec_securejoin_qr_multi_device(bob, &[alice1, alice2], &qr) .await; + for _ in 0..3 { + alice2.assert_warn("blocked").await; + } assert_eq!(get_chat_cnt(alice1).await?, chat_cnt + 1); assert_eq!(get_chat_cnt(alice2).await?, chat_cnt); Ok(()) @@ -5269,6 +5307,7 @@ async fn test_nonimage_with_png_ext() -> Result<()> { msg.get_filename().unwrap().contains("screenshot"), vt == Viewtype::File ); + alice.assert_error("Unknown format").await; let msg_bob = bob.recv_msg(&sent_msg).await; assert_eq!(msg_bob.viewtype, Viewtype::File); assert_eq!(msg_bob.get_filemime().unwrap(), "application/octet-stream"); @@ -5592,6 +5631,7 @@ async fn test_non_member_cannot_modify_member_list() -> Result<()> { remove_contact_from_chat(bob, bob_chat_id, bob_alice_contact_id).await?; let bob_sent_add_msg = bob.pop_sent_msg().await; alice.recv_msg_trash(&bob_sent_add_msg).await; + alice.assert_warn("no contact id").await; assert_eq!(get_chat_contacts(alice, alice_chat_id).await?.len(), 1); Ok(()) } @@ -5968,6 +6008,8 @@ async fn test_receive_edit_request_after_removal() -> Result<()> { bob.recv_msg_trash(&sent2).await; assert_eq!(bob_chat_id.get_msg_cnt(bob).await?, E2EE_INFO_MSGS); + bob.assert_warn("Edit message: Database entry does not exist") + .await; Ok(()) } @@ -6061,6 +6103,7 @@ async fn test_send_delete_request() -> Result<()> { let bob2 = &tcm.bob().await; bob2.recv_msg_opt(&sent2).await; assert!(bob2.recv_msg_opt(&sent1).await.is_none()); + bob2.assert_warn("not found").await; // Alice has another device, and there is also nothing at the end let alice2 = &tcm.alice().await; @@ -6352,6 +6395,9 @@ async fn test_create_unencrypted_group_chat() -> Result<()> { assert!(res.is_err()); add_contact_to_chat(alice, chat_id, charlie_address_contact_id).await?; + alice + .assert_warn("No good message identifying the chat found") + .await; let chat = Chat::load_from_db(alice, chat_id).await?; assert!(!chat.is_encrypted(alice).await?); @@ -6368,6 +6414,7 @@ async fn test_create_group_invalid_name() -> Result<()> { let chat_id = create_group(alice, " ").await?; let chat = Chat::load_from_db(alice, chat_id).await?; assert_eq!(chat.get_name(), "…"); + alice.assert_error("Invalid chat name").await; Ok(()) } @@ -6391,6 +6438,7 @@ async fn test_no_avatar_in_adhoc_chats() -> Result<()> { .await? .unwrap() .chat_id; + alice.assert_warn("unencrypted message").await; // Test that setting avatar in ad hoc group is not possible. let file = alice.dir.path().join("avatar.png"); diff --git a/src/configure.rs b/src/configure.rs index 589c7eb243..c426f0caec 100644 --- a/src/configure.rs +++ b/src/configure.rs @@ -759,6 +759,14 @@ mod tests { .unwrap(); t.set_config(Config::MailPw, Some("123456")).await.unwrap(); assert!(t.configure().await.is_err()); + + t.assert_many(vec![ + (false, "SMTP failed to connect", 6), + (false, "IMAP failed to connect", 6), + (false, "DNS resolution", 20), + (false, "configure failed", 1), + ]) + .await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] diff --git a/src/contact/contact_tests.rs b/src/contact/contact_tests.rs index 44a62253fd..40b696c420 100644 --- a/src/contact/contact_tests.rs +++ b/src/contact/contact_tests.rs @@ -162,7 +162,7 @@ async fn test_search_contacts_from_group() -> Result<()> { let bob = &tcm.bob().await; let fiona = &tcm.fiona().await; - let alice_chat_id = chat::create_group(alice, "").await?; + let alice_chat_id = chat::create_group(alice, "group").await?; let qr = get_securejoin_qr(alice, Some(alice_chat_id)).await?; let bob_chat_id = tcm.exec_securejoin_qr(bob, alice, &qr).await; tcm.exec_securejoin_qr(fiona, alice, &qr).await; @@ -224,6 +224,7 @@ async fn test_add_or_lookup() { "\nWonderland, Alice \n", ); assert_eq!(Contact::add_address_book(&t, book).await.unwrap(), 4); + t.assert_warn(r#"invalid address "+1234567890""#).await; // check first added contact, this modifies authname because it is empty let (contact_id, sth_modified) = Contact::add_or_lookup( @@ -1081,6 +1082,11 @@ async fn test_was_seen_recently_event() -> Result<()> { .get_matching(|evt| matches!(evt, EventType::ContactsChanged { .. })) .await; } + // this warning is only printed when `RecentlySeenLoop` is dropped, + // so we can't assert it otherwise. + drop(recently_seen_loop); + bob.assert_warn("receiving from an empty and closed channel") + .await; Ok(()) } diff --git a/src/context/context_tests.rs b/src/context/context_tests.rs index 1fff54e085..c372552b44 100644 --- a/src/context/context_tests.rs +++ b/src/context/context_tests.rs @@ -617,6 +617,11 @@ async fn test_cache_is_cleared_when_io_is_started() -> Result<()> { // but it should invalidate the caches: alice.start_io().await; + alice + .assert_warn("No IMAP connection candidates provided") + .await; + alice.assert_warn("IMAP got rate limited").await; + assert_eq!( alice.get_config(Config::Displayname).await?, Some("Alice 2".to_string()) diff --git a/src/e2ee.rs b/src/e2ee.rs index 77606419c2..36e06e47bd 100644 --- a/src/e2ee.rs +++ b/src/e2ee.rs @@ -141,10 +141,9 @@ Sent with my Delta Chat Messenger: https://delta.chat"; let mut msg = Message::new_text("Hello!".to_string()); assert!(chat::send_msg(alice, chat.id, &mut msg).await.is_err()); - assert_eq!( - msg.error().unwrap(), - "\u{26a0}\u{fe0f} Your email provider example.org requires end-to-end encryption which is not setup yet." - ); + let expected_error = "\u{26a0}\u{fe0f} Your email provider example.org requires end-to-end encryption which is not setup yet."; + assert_eq!(msg.error().unwrap(), expected_error); + alice.assert_warn(expected_error).await; let info_msg = alice.get_last_msg().await; assert_eq!( info_msg.get_info_type(), diff --git a/src/ephemeral/ephemeral_tests.rs b/src/ephemeral/ephemeral_tests.rs index 0098aa4dfa..a253a7cc4b 100644 --- a/src/ephemeral/ephemeral_tests.rs +++ b/src/ephemeral/ephemeral_tests.rs @@ -223,6 +223,8 @@ async fn test_ephemeral_timer_rollback() -> Result<()> { Timer::Disabled ); assert_eq!(chat_bob.get_ephemeral_timer(&bob.ctx).await?, enabled(60)); + bob.assert_warn("Ignoring ephemeral timer change to Disabled") + .await; // Alice receives message from Bob alice.recv_msg(&sent_timer_change).await; @@ -838,6 +840,10 @@ async fn test_ephemeral_timer_non_member() -> Result<()> { Timer::Disabled ); + alice + .assert_warn("Ignoring ephemeral timer change to Enabled") + .await; + Ok(()) } @@ -870,7 +876,11 @@ async fn test_disappearing_unknown_viewtype() -> Result<()> { // This should not fail. delete_expired_messages(alice, time()).await?; - + alice + .assert_warn( + "Using default viewtype for ephemeral handling.: Integer 70 out of range at index 2", + ) + .await; Ok(()) } @@ -902,6 +912,10 @@ async fn test_delete_device_after_unknown_viewtype() -> Result<()> { // This should not fail. delete_expired_messages(alice, time()).await?; - + alice + .assert_warn( + "Using default viewtype for delete-old handling.: Integer 70 out of range at index 2", + ) + .await; Ok(()) } diff --git a/src/events.rs b/src/events.rs index d8073399f4..fc577ef5b5 100644 --- a/src/events.rs +++ b/src/events.rs @@ -163,3 +163,15 @@ pub struct Event { /// These are documented in `deltachat.h` as the `DC_EVENT_*` constants. pub typ: EventType, } + +impl Event { + /// todo + pub fn is_warn(&self) -> bool { + self.typ.get_warn().is_some() + } + + /// todo + pub fn is_error(&self) -> bool { + self.typ.get_error().is_some() + } +} diff --git a/src/events/payload.rs b/src/events/payload.rs index 8300f02b1c..653f035ec3 100644 --- a/src/events/payload.rs +++ b/src/events/payload.rs @@ -448,3 +448,21 @@ pub enum EventType { n: u64, }, } + +impl EventType { + /// todo + pub fn get_warn(&self) -> Option<&String> { + match self { + Self::Warning(s) => Some(s), + _ => None, + } + } + + /// todo + pub fn get_error(&self) -> Option<&String> { + match self { + Self::Error(s) | Self::ErrorSelfNotInGroup(s) => Some(s), + _ => None, + } + } +} diff --git a/src/imex.rs b/src/imex.rs index 012c2d5f86..567b23b60d 100644 --- a/src/imex.rs +++ b/src/imex.rs @@ -867,6 +867,7 @@ mod tests { { panic!("got error on import: {err:#}"); } + context2.assert_warn("Failed to import secret key").await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -874,7 +875,7 @@ mod tests { let alice = &TestContext::new_alice().await; let chat = alice.create_chat(alice).await; let sent = alice.send_text(chat.id, "Encrypted with old key").await; - let export_dir = tempfile::tempdir().unwrap(); + let export_dir = tempfile::tempdir()?; let alice = &TestContext::new().await; alice.configure_addr("alice@example.org").await; @@ -892,7 +893,6 @@ mod tests { // Importing a second key is not allowed anymore, // even as a non-default key. assert_eq!(key::load_self_secret_key(alice).await?, old_key); - assert_eq!(key::load_self_secret_keyring(alice).await?, vec![old_key]); let msg = alice.recv_msg(&sent).await; @@ -900,6 +900,19 @@ mod tests { assert_eq!(msg.chat_id, alice.get_self_chat().await.id); assert_eq!(msg.get_text(), "Encrypted with old key"); + alice + .assert_many(vec![ + ( + false, + "rPGP error: unexpected block type: PGP PUBLIC KEY BLOCK", + 1, + ), + (false, "UNIQUE constraint failed", 1), + (true, "No private keys found in /tmp/", 1), + (false, "IMEX failed to complete", 1), + ]) + .await; + Ok(()) } @@ -939,6 +952,8 @@ mod tests { .await .is_err() ); + context2.assert_error("file is not a database").await; + context2.assert_warn("IMEX failed to complete").await; assert!( imex(&context2, ImexMode::ImportBackup, backup.as_ref(), None) @@ -1056,14 +1071,9 @@ mod tests { // Some UIs show the error from the event to the user. // Therefore, it must also be a user-facing string, rather than some technical info: - let err_event = context2 - .evtracker - .get_matching(|evt| matches!(evt, EventType::Error(_))) - .await; - let EventType::Error(err_msg) = err_event else { - unreachable!() - }; - assert!(err_msg.starts_with("This profile is from a newer version of Delta Chat. Please update Delta Chat and try again")); + context2.assert_error("This profile is from a newer version of Delta Chat. Please update Delta Chat and try again").await; + + context2.assert_warn("IMEX failed to complete").await; context2 .evtracker diff --git a/src/imex/transfer.rs b/src/imex/transfer.rs index 5021d78dfe..79eee1bc25 100644 --- a/src/imex/transfer.rs +++ b/src/imex/transfer.rs @@ -488,12 +488,16 @@ mod tests { // Try to overwrite an existing profile. let err = get_backup(ctx1, provider.qr()).await.unwrap_err(); assert!(format!("{err:#}").contains("Cannot import backups to accounts in use")); + ctx1.assert_error("Cannot import backups to accounts in use") + .await; // ctx0 is supposed to also finish, and emit an error: provider.await.unwrap(); ctx0.evtracker .get_matching(|e| matches!(e, EventType::Error(_))) .await; + ctx0.assert_error("Failed to write backup into QUIC stream") + .await; assert_eq!(ctx1.get_primary_self_addr().await?, "bob@example.net"); diff --git a/src/log.rs b/src/log.rs index 14bad7e988..a8178a2c63 100644 --- a/src/log.rs +++ b/src/log.rs @@ -143,9 +143,11 @@ mod tests { assert_eq!(t.get_last_error(), ""); error!(t, "foo-error"); + t.assert_error("foo-error").await; assert_eq!(t.get_last_error(), "foo-error"); warn!(t, "foo-warning"); + t.assert_warn("foo-warning").await; assert_eq!(t.get_last_error(), "foo-error"); info!(t, "foo-info"); @@ -153,6 +155,8 @@ mod tests { error!(t, "bar-error"); error!(t, "baz-error"); + t.assert_error("bar-error").await; + t.assert_error("baz-error").await; assert_eq!(t.get_last_error(), "baz-error"); Ok(()) diff --git a/src/message/message_tests.rs b/src/message/message_tests.rs index 13593b57bb..9f73217a6d 100644 --- a/src/message/message_tests.rs +++ b/src/message/message_tests.rs @@ -363,7 +363,7 @@ async fn test_pre_and_post_msgs_deleted_ex(reorder: bool) -> Result<()> { let mut tcm = TestContextManager::new(); let alice = &tcm.alice().await; let bob = &tcm.bob().await; - let alice_chat_id = alice.create_group_with_members("", &[bob]).await; + let alice_chat_id = alice.create_group_with_members("group", &[bob]).await; let file_bytes = include_bytes!("../../test-data/image/screenshot.gif"); let mut msg = Message::new(Viewtype::Image); @@ -438,6 +438,7 @@ async fn test_get_state() -> Result<()> { set_msg_failed(&alice, &mut alice_msg, "badly failed").await?; assert_state(&alice, alice_msg.id, MessageState::OutFailed).await; + alice.assert_warn("badly failed").await; // check incoming message states on receiver side let bob_msg = bob.recv_msg(&payload).await; diff --git a/src/mimefactory/mimefactory_tests.rs b/src/mimefactory/mimefactory_tests.rs index 937fdacbd6..e251ff3855 100644 --- a/src/mimefactory/mimefactory_tests.rs +++ b/src/mimefactory/mimefactory_tests.rs @@ -747,6 +747,13 @@ async fn test_remove_member_bcc() -> Result<()> { } } + alice + .assert_warn("No good message identifying the chat found") + .await; + alice + .assert_warn("No good message identifying the chat found") + .await; + Ok(()) } diff --git a/src/mimeparser/mimeparser_tests.rs b/src/mimeparser/mimeparser_tests.rs index 562ea644a4..ed05b314fe 100644 --- a/src/mimeparser/mimeparser_tests.rs +++ b/src/mimeparser/mimeparser_tests.rs @@ -287,7 +287,9 @@ async fn test_get_attachment_filename_apostrophed_invalid() { include_bytes!("../../test-data/message/attach_filename_apostrophed_invalid.eml"), ); let filename = get_attachment_filename(&t, &mail.subparts[1]).unwrap(); - assert_eq!(filename, Some("somedäüta.html.zip".to_string())) + assert_eq!(filename, Some("somedäüta.html.zip".to_string())); + t.assert_warn("apostrophed encoding invalid: somedäüta.html.zip") + .await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -343,6 +345,9 @@ async fn test_parse_first_addr() { let mimeparser = MimeMessage::from_bytes(&context.ctx, &raw[..]).await; assert!(mimeparser.is_err()); + context + .assert_warn("Invalid address found: must contain a '@' symbol") + .await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -1425,7 +1430,7 @@ async fn test_intended_recipient_fingerprint() -> Result<()> { let t_fp = key::load_self_public_key(t).await?.dc_fingerprint(); t.set_config_bool(Config::BccSelf, false).await.unwrap(); let members = [tcm.bob().await, tcm.fiona().await]; - let chat_id = chat::create_group(t, "").await?; + let chat_id = chat::create_group(t, "group").await?; chat::send_text_msg(t, chat_id, "hi!".to_string()).await?; assert!(t.pop_sent_msg_opt().await.is_none()); @@ -2030,6 +2035,7 @@ async fn test_multiple_autocrypt_hdrs() -> Result<()> { .msg_ids[0]; let msg = Message::load_from_db(bob, msg_id).await?; assert!(msg.get_showpadlock()); + bob.assert_warn("Unknown Autocrypt attribute found").await; Ok(()) } diff --git a/src/mimeparser/shared_secret_decryption_tests.rs b/src/mimeparser/shared_secret_decryption_tests.rs index f6aed1d1eb..2dbfb90af2 100644 --- a/src/mimeparser/shared_secret_decryption_tests.rs +++ b/src/mimeparser/shared_secret_decryption_tests.rs @@ -141,7 +141,10 @@ async fn test_broadcast_security_attacker_signature() -> Result<()> { Some(charlie), Some("This sender is not allowed to encrypt with this secret key"), ) - .await + .await?; + bob.assert_warn("This sender is not allowed to encrypt with this secret key") + .await; + Ok(()) } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -163,7 +166,10 @@ async fn test_broadcast_security_no_signature() -> Result<()> { None, Some("Unsigned message is not allowed to be encrypted with this shared secret"), ) - .await + .await?; + bob.assert_warn("Unsigned message is not allowed to be encrypted with this shared secret") + .await; + Ok(()) } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -211,7 +217,10 @@ async fn test_qr_code_security() -> Result<()> { Some(charlie), Some("This sender is not allowed to encrypt with this secret key"), ) - .await + .await?; + bob.assert_warn("This sender is not allowed to encrypt with this secret key") + .await; + Ok(()) } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -253,5 +262,9 @@ async fn test_unknown_secret() -> Result<()> { Some(alice), Some("Could not find symmetric secret for session key"), ) - .await + .await?; + bob.assert_warn("Could not find symmetric secret for session key") + .await; + bob.assert_warn("unencrypted message").await; + Ok(()) } diff --git a/src/net/http.rs b/src/net/http.rs index aaaa4599d2..875b2ac199 100644 --- a/src/net/http.rs +++ b/src/net/http.rs @@ -541,6 +541,8 @@ mod tests { None ); + t.assert_warn("No such file or directory (os error 2)") + .await; Ok(()) } } diff --git a/src/peer_channels.rs b/src/peer_channels.rs index 9e7e8a1af6..17cf1d345b 100644 --- a/src/peer_channels.rs +++ b/src/peer_channels.rs @@ -821,6 +821,7 @@ mod tests { .node_id ] ); + bob.assert_warn("Cannot add iroh peer").await; Ok(()) } @@ -1091,7 +1092,7 @@ mod tests { tokio::time::sleep(std::time::Duration::from_secs(1)).await; } }; - + fiona.assert_warn("Missing key for bob@example.net").await; let realtime_receive_loop = async { loop { let event = fiona.evtracker.recv().await.unwrap(); diff --git a/src/qr/qr_tests.rs b/src/qr/qr_tests.rs index 71c631f908..3db74ca1c2 100644 --- a/src/qr/qr_tests.rs +++ b/src/qr/qr_tests.rs @@ -584,6 +584,10 @@ async fn test_withdraw_joinbroadcast() -> Result<()> { assert_eq!(bob_chat.is_self_in_chat(bob).await?, true); assert_eq!(get_chat_contacts(alice, chat_id).await?.len(), 1); + alice + .assert_warn("Could not find symmetric secret for session key") + .await; + alice.assert_warn("unencrypted message").await; Ok(()) } diff --git a/src/receive_imf.rs b/src/receive_imf.rs index 8d8144e48f..04dc5c29a4 100644 --- a/src/receive_imf.rs +++ b/src/receive_imf.rs @@ -2466,7 +2466,7 @@ async fn handle_post_message( .context("expected Post-Message to have a message id")?; let Some(msg_id) = message::rfc724_mid_exists(context, &rfc724_mid).await? else { - warn!( + info!( context, "handle_post_message: {rfc724_mid}: Database entry does not exist." ); @@ -3479,13 +3479,13 @@ async fn group_changes_msgs( ) -> Result)>> { let mut group_changes_msgs: Vec<(String, SystemMessage, Option)> = Vec::new(); if !added_ids.is_empty() { - warn!( + info!( context, "Implicit addition of {added_ids:?} to chat {chat_id}." ); } if !removed_ids.is_empty() { - warn!( + info!( context, "Implicit removal of {removed_ids:?} from chat {chat_id}." ); diff --git a/src/receive_imf/receive_imf_tests.rs b/src/receive_imf/receive_imf_tests.rs index 36597f08ea..9079da8db4 100644 --- a/src/receive_imf/receive_imf_tests.rs +++ b/src/receive_imf/receive_imf_tests.rs @@ -267,7 +267,7 @@ async fn test_mdn_and_alias() -> Result<()> { let chats = Chatlist::try_load(&alice, 0, None, None).await?; assert_eq!(chats.len(), 1); - + alice.assert_warn("unencrypted message").await; Ok(()) } @@ -299,6 +299,8 @@ async fn test_no_from() { .unwrap() .unwrap(); + t.assert_warn("No from in message").await; + // Check that tombstone MsgId is returned. assert_eq!(received.msg_ids.len(), 1); assert!(!received.msg_ids[0].is_special()); @@ -355,6 +357,8 @@ async fn test_no_message_id_header() { let chats = Chatlist::try_load(&t, 0, None, None).await.unwrap(); // Check that the message is not shown to the user: assert!(chats.is_empty()); + + t.assert_warn("No from in message").await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -481,43 +485,51 @@ async fn test_cc_to_contact() { #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_tiscali() { - test_parse_ndn( - "alice@tiscali.it", - "shenauithz@testrun.org", - "Mr.un2NYERi1RM.lbQ5F9q-QyJ@tiscali.it", - include_bytes!("../../test-data/message/tiscali_ndn.eml"), - Some("Delivery status notification – This is an automatically generated Delivery Status Notification. \n\nDelivery to the following recipients was aborted after 2 second(s):\n\n * shenauithz@testrun.org"), - ) - .await; + let msg = "Delivery status notification – This is an automatically generated Delivery Status Notification. \n\nDelivery to the following recipients was aborted after 2 second(s):\n\n * shenauithz@testrun.org"; + let (t, _) = test_parse_ndn( + "alice@tiscali.it", + "shenauithz@testrun.org", + "Mr.un2NYERi1RM.lbQ5F9q-QyJ@tiscali.it", + include_bytes!("../../test-data/message/tiscali_ndn.eml"), + Some(msg), + ) + .await; + t.assert_warn("DSN without action").await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_testrun() { - test_parse_ndn( - "alice@testrun.org", - "hcksocnsofoejx@five.chat", - "Mr.A7pTA5IgrUA.q4bP41vAJOp@testrun.org", - include_bytes!("../../test-data/message/testrun_ndn.eml"), - Some("Undelivered Mail Returned to Sender – This is the mail system at host hq5.merlinux.eu.\n\nI\'m sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It\'s attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mail.five.chat[195.62.125.103] said: 550 5.1.1\n : Recipient address rejected: User unknown in\n virtual mailbox table (in reply to RCPT TO command)"), - ) - .await; + let msg = "Undelivered Mail Returned to Sender – This is the mail system at host hq5.merlinux.eu.\n\nI\'m sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It\'s attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mail.five.chat[195.62.125.103] said: 550 5.1.1\n : Recipient address rejected: User unknown in\n virtual mailbox table (in reply to RCPT TO command)"; + let (t, _) = test_parse_ndn( + "alice@testrun.org", + "hcksocnsofoejx@five.chat", + "Mr.A7pTA5IgrUA.q4bP41vAJOp@testrun.org", + include_bytes!("../../test-data/message/testrun_ndn.eml"), + Some(msg), + ) + .await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_yahoo() { - test_parse_ndn( - "alice@yahoo.com", - "haeclirth.sinoenrat@yahoo.com", - "1680295672.3657931.1591783872936@mail.yahoo.com", - include_bytes!("../../test-data/message/yahoo_ndn.eml"), - Some("Failure Notice – Sorry, we were unable to deliver your message to the following address.\n\n:\n554: delivery error: dd Not a valid recipient - atlas117.free.mail.ne1.yahoo.com [...]"), - ) - .await; + let msg = "Failure Notice – Sorry, we were unable to deliver your message to the following address.\n\n:\n554: delivery error: dd Not a valid recipient - atlas117.free.mail.ne1.yahoo.com [...]"; + let (t, _) = test_parse_ndn( + "alice@yahoo.com", + "haeclirth.sinoenrat@yahoo.com", + "1680295672.3657931.1591783872936@mail.yahoo.com", + include_bytes!("../../test-data/message/yahoo_ndn.eml"), + Some(msg), + ) + .await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_gmail() { - test_parse_ndn( + let msg = "Delivery Status Notification (Failure) – ** Die Adresse wurde nicht gefunden **\n\nIhre Nachricht wurde nicht an assidhfaaspocwaeofi@gmail.com zugestellt, weil die Adresse nicht gefunden wurde oder keine E-Mails empfangen kann.\n\nHier erfahren Sie mehr: https://support.google.com/mail/?p=NoSuchUser\n\nAntwort:\n\n550 5.1.1 The email account that you tried to reach does not exist. Please try double-checking the recipient\'s email address for typos or unnecessary spaces. Learn more at https://support.google.com/mail/?p=NoSuchUser i18sor6261697wrs.38 - gsmtp"; + let (t, _) = test_parse_ndn( "alice@gmail.com", "assidhfaaspocwaeofi@gmail.com", "CABXKi8zruXJc_6e4Dr087H5wE7sLp+u250o0N2q5DdjF_r-8wg@mail.gmail.com", @@ -525,55 +537,65 @@ async fn test_parse_ndn_gmail() { Some("Delivery Status Notification (Failure) – ** Die Adresse wurde nicht gefunden **\n\nIhre Nachricht wurde nicht an assidhfaaspocwaeofi@gmail.com zugestellt, weil die Adresse nicht gefunden wurde oder keine E-Mails empfangen kann.\n\nHier erfahren Sie mehr: https://support.google.com/mail/?p=NoSuchUser\n\nAntwort:\n\n550 5.1.1 The email account that you tried to reach does not exist. Please try double-checking the recipient\'s email address for typos or unnecessary spaces. Learn more at https://support.google.com/mail/?p=NoSuchUser i18sor6261697wrs.38 - gsmtp"), ) .await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_gmx() { - test_parse_ndn( - "alice@gmx.com", - "snaerituhaeirns@gmail.com", - "9c9c2a32-056b-3592-c372-d7e8f0bd4bc2@gmx.de", - include_bytes!("../../test-data/message/gmx_ndn.eml"), - Some("Mail delivery failed: returning message to sender – This message was created automatically by mail delivery software.\n\nA message that you sent could not be delivered to one or more of\nits recipients. This is a permanent error. The following address(es)\nfailed:\n\nsnaerituhaeirns@gmail.com:\nSMTP error from remote server for RCPT TO command, host: gmail-smtp-in.l.google.com (66.102.1.27) reason: 550-5.1.1 The email account that you tried to reach does not exist. Please\n try\n550-5.1.1 double-checking the recipient\'s email address for typos or\n550-5.1.1 unnecessary spaces. Learn more at\n550 5.1.1 https://support.google.com/mail/?p=NoSuchUser f6si2517766wmc.21\n9 - gsmtp [...]"), - ) - .await; + let msg = "Mail delivery failed: returning message to sender – This message was created automatically by mail delivery software.\n\nA message that you sent could not be delivered to one or more of\nits recipients. This is a permanent error. The following address(es)\nfailed:\n\nsnaerituhaeirns@gmail.com:\nSMTP error from remote server for RCPT TO command, host: gmail-smtp-in.l.google.com (66.102.1.27) reason: 550-5.1.1 The email account that you tried to reach does not exist. Please\n try\n550-5.1.1 double-checking the recipient\'s email address for typos or\n550-5.1.1 unnecessary spaces. Learn more at\n550 5.1.1 https://support.google.com/mail/?p=NoSuchUser f6si2517766wmc.21\n9 - gsmtp [...]"; + let (t, _) = test_parse_ndn( + "alice@gmx.com", + "snaerituhaeirns@gmail.com", + "9c9c2a32-056b-3592-c372-d7e8f0bd4bc2@gmx.de", + include_bytes!("../../test-data/message/gmx_ndn.eml"), + Some(msg), + ) + .await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_posteo() { - test_parse_ndn( - "alice@posteo.org", - "hanerthaertidiuea@gmx.de", - "04422840-f884-3e37-5778-8192fe22d8e1@posteo.de", - include_bytes!("../../test-data/message/posteo_ndn.eml"), - Some("Undelivered Mail Returned to Sender – This is the mail system at host mout01.posteo.de.\n\nI\'m sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It\'s attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mx01.emig.gmx.net[212.227.17.5] said: 550\n Requested action not taken: mailbox unavailable (in reply to RCPT TO\n command)"), - ) - .await; + let msg = "Undelivered Mail Returned to Sender – This is the mail system at host mout01.posteo.de.\n\nI\'m sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It\'s attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mx01.emig.gmx.net[212.227.17.5] said: 550\n Requested action not taken: mailbox unavailable (in reply to RCPT TO\n command)"; + let (t, _) = test_parse_ndn( + "alice@posteo.org", + "hanerthaertidiuea@gmx.de", + "04422840-f884-3e37-5778-8192fe22d8e1@posteo.de", + include_bytes!("../../test-data/message/posteo_ndn.eml"), + Some(msg), + ) + .await; + t.assert_warn(msg).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_testrun_2() { - test_parse_ndn( - "alice@example.org", - "bob@example.org", - "Mr.5xqflwt0YFv.IXDFfHauvWx@testrun.org", - include_bytes!("../../test-data/message/testrun_ndn_2.eml"), - Some("Undelivered Mail Returned to Sender – This is the mail system at host hq5.merlinux.eu.\n\nI'm sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It's attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: Host or domain name not found. Name service error for\n name=echedelyr.tk type=AAAA: Host not found"), - ) - .await; + let msg = "Undelivered Mail Returned to Sender – This is the mail system at host hq5.merlinux.eu.\n\nI'm sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It's attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: Host or domain name not found. Name service error for\n name=echedelyr.tk type=AAAA: Host not found"; + let (t, _) = test_parse_ndn( + "alice@example.org", + "bob@example.org", + "Mr.5xqflwt0YFv.IXDFfHauvWx@testrun.org", + include_bytes!("../../test-data/message/testrun_ndn_2.eml"), + Some(msg), + ) + .await; + t.assert_warn(msg).await; } /// Tests that text part is not squashed into OpenPGP attachment. #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_parse_ndn_with_attachment() { - test_parse_ndn( - "alice@example.org", - "bob@example.net", - "Mr.I6Da6dXcTel.TroC5J3uSDH@example.org", - include_bytes!("../../test-data/message/ndn_with_attachment.eml"), - Some("Undelivered Mail Returned to Sender – This is the mail system at host relay01.example.org.\n\nI'm sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It's attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mx2.example.net[80.241.60.215] said: 552 5.2.2\n : Recipient address rejected: Mailbox quota exceeded (in\n reply to RCPT TO command)\n\n: host mx1.example.net[80.241.60.212] said: 552 5.2.2\n : Recipient address rejected: Mailbox quota\n exceeded (in reply to RCPT TO command)") - ) - .await; + let msg = "Undelivered Mail Returned to Sender – This is the mail system at host relay01.example.org.\n\nI'm sorry to have to inform you that your message could not\nbe delivered to one or more recipients. It's attached below.\n\nFor further assistance, please send mail to postmaster.\n\nIf you do so, please include this problem report. You can\ndelete your own text from the attached returned message.\n\n The mail system\n\n: host mx2.example.net[80.241.60.215] said: 552 5.2.2\n : Recipient address rejected: Mailbox quota exceeded (in\n reply to RCPT TO command)\n\n: host mx1.example.net[80.241.60.212] said: 552 5.2.2\n : Recipient address rejected: Mailbox quota\n exceeded (in reply to RCPT TO command)"; + let (t, _) = test_parse_ndn( + "alice@example.org", + "bob@example.net", + "Mr.I6Da6dXcTel.TroC5J3uSDH@example.org", + include_bytes!("../../test-data/message/ndn_with_attachment.eml"), + Some(msg), + ) + .await; + t.assert_warn("Missing attachment").await; + t.assert_warn(msg).await; } /// Test that DSN is not treated as NDN if Action: is not "failed" @@ -658,6 +680,7 @@ async fn test_resend_after_ndn() -> Result<()> { ) .await; chat::resend_msgs(&t, &[msg_id]).await?; + t.assert_warn("Undelivered Mail Returned to Sender").await; let msg = Message::load_from_db(&t, msg_id).await?; assert_eq!(msg.state, MessageState::OutPending); assert_eq!(msg.error(), None); @@ -719,6 +742,10 @@ async fn test_parse_ndn_group_msg() -> Result<()> { *msgs.last().unwrap(), ChatItem::Message { msg_id } if msg_id == msg.id )); + + t.assert_warn("Delivery Status Notification (Failure)") + .await; + Ok(()) } @@ -767,7 +794,10 @@ async fn test_concat_multiple_ndns() -> Result<()> { receive_imf(&t, raw.as_bytes(), false).await?; let msg = Message::load_from_db(&t, msg_id).await?; - assert_eq!(msg.error(), Some([err.clone(), err].join("\n\n"))); + assert_eq!(msg.error(), Some([err.clone(), err.clone()].join("\n\n"))); + + t.assert_warn(&err).await; + t.assert_warn(&err).await; Ok(()) } @@ -790,6 +820,7 @@ async fn test_html_only_mail() { msg.text, "Guten Abend,\n\nLots of text\n\ntext with Umlaut ä...\n\nMfG\n\n--------------------------------------\n\n[Camping ](https://example.com/)\n\nsomeaddress\n\nsometown" ); + t.assert_warn("Missing attachment").await; } static GH_MAILINGLIST: &[u8] = @@ -1666,6 +1697,7 @@ async fn test_save_mime_headers_off() -> anyhow::Result<()> { assert_eq!(msg.get_text(), "hi!"); let html = msg.id.get_html(&bob).await?; assert!(html.is_none()); + bob.assert_warn("get_html: no mime").await; Ok(()) } @@ -2634,10 +2666,16 @@ Second thread."#; chat::add_contact_to_chat(&alice, alice_first_msg.chat_id, alice_fiona_contact_id).await?; let alice_first_invite = alice.pop_sent_msg().await; let fiona_first_invite = fiona.recv_msg(&alice_first_invite).await; + fiona + .assert_warn(r#"Added "fiona@example.net" has no gossiped key."#) + .await; chat::add_contact_to_chat(&alice, alice_second_msg.chat_id, alice_fiona_contact_id).await?; let alice_second_invite = alice.pop_sent_msg().await; let fiona_second_invite = fiona.recv_msg(&alice_second_invite).await; + fiona + .assert_warn(r#"Added "fiona@example.net" has no gossiped key."#) + .await; // Fiona was added to two separate chats and should see two separate chats, even though they // don't have different group IDs to distinguish them. @@ -2900,7 +2938,7 @@ async fn test_invalid_to_address() -> Result<()> { // receive_imf should not fail on this mail with invalid To: field receive_imf(&alice, mime, false).await?; - + alice.assert_warn("unencrypted message").await; Ok(()) } @@ -3353,6 +3391,8 @@ async fn test_outgoing_undecryptable() -> Result<()> { // The device message mustn't be added too frequently. assert_eq!(alice.get_last_msg_in(dev_chat_id).await.id, dev_msg.id); + alice.assert_warn("decryption failed").await; + alice.assert_warn("decryption failed").await; Ok(()) } @@ -3478,7 +3518,9 @@ async fn test_forged_from_and_no_valid_signatures() -> Result<()> { let raw = String::from_utf8(raw.to_vec())?.replace("alice@example.org", "clarice@example.org"); let received_msg = receive_imf(t, raw.as_bytes(), false).await?.unwrap(); assert!(received_msg.chat_id.is_trash()); - + t.assert_warn("From header in encrypted part doesn't match the outer one") + .await; + t.assert_warn("From header is forged").await; Ok(()) } @@ -4495,6 +4537,7 @@ async fn test_outgoing_msg_forgery() -> Result<()> { bob.configure_addr("bob@example.net").await; imex(bob, ImexMode::ImportSelfKeys, export_dir.path(), None).await?; assert_eq!(crate::key::load_self_secret_keyring(bob).await?.len(), 1); + bob.assert_warn("Failed to import secret key").await; let malice = &tcm.unconfigured().await; malice.configure_addr(alice_addr).await; @@ -4507,7 +4550,7 @@ async fn test_outgoing_msg_forgery() -> Result<()> { let sent_msg = malice.send_text(malice_chat_id, "hi from malice").await; let msg = alice.recv_msg_opt(&sent_msg).await; assert!(msg.is_none()); - + alice.assert_warn("unencrypted message").await; Ok(()) } @@ -4594,6 +4637,8 @@ async fn test_protected_group_add_remove_member_missing_key() -> Result<()> { msg.get_text(), stock_str::msg_del_member_local(alice, alice_bob_id, ContactId::SELF).await ); + alice.assert_warn("Missing key for bob@example.net").await; + alice.assert_warn("Missing key for bob@example.net").await; Ok(()) } @@ -4651,6 +4696,7 @@ Chat-Group-Member-Removed: charlie@example.com", false, ) .await?; + bob.assert_warn("unencrypted message").await; assert_eq!(get_chat_cnt(bob).await?, chat_cnt); Ok(()) } @@ -4742,7 +4788,12 @@ async fn test_forged_from() -> Result<()> { // We take the address from the encrypted part // and send replies there. assert_eq!(contact.get_addr(), "bob@example.net"); - + alice + .assert_warn(r#"Autocrypt header address "bob@example.net" is not "notbob@example.net""#) + .await; + alice + .assert_warn("From header in encrypted part doesn't match the outer one") + .await; Ok(()) } @@ -4889,6 +4940,7 @@ async fn test_receive_vcard() -> Result<()> { assert_eq!(&parsed[0].addr, "claire@example.org"); } else { assert_eq!(&parsed[0].addr, ""); + alice.assert_warn("Not a valid DeltaChat vCard").await; } Ok(()) } @@ -5136,7 +5188,7 @@ async fn test_dont_verify_by_verified_by_unknown() -> Result<()> { let a0_fiona = a0.add_or_lookup_contact(fiona).await; assert_eq!(a0_fiona.get_verifier_id(a0).await?, Some(Some(a0_bob.id))); - let chat_id = a0.create_group_with_members("", &[fiona]).await; + let chat_id = a0.create_group_with_members("group", &[fiona]).await; a0.set_chat_protected(chat_id).await; a1.recv_msg(&a0.send_text(chat_id, "Hi").await).await; let a1_fiona = a1.add_or_lookup_contact(fiona).await; @@ -5217,6 +5269,9 @@ async fn test_recv_outgoing_msg_no_intended_recipient_fingerprint() -> Result<() // Alice does not have Bob's key. // Message is encrypted, but is received in ad hoc group with Bob's address. let rcvd_msg = receive_imf(alice, payload, false).await?.unwrap(); + alice + .assert_warn("No key-contact looked up. Downgrading to AdHocGroup.") + .await; let msg_alice = Message::load_from_db(alice, rcvd_msg.msg_ids[0]).await?; assert!(msg_alice.get_showpadlock()); @@ -5327,6 +5382,7 @@ async fn test_no_address_contact_added_into_group() -> Result<()> { // Unencrypted message should not even be assigned to encrypted chat. assert_ne!(msg.chat_id, alice_chat_id); + alice.assert_warn("unencrypted message").await; Ok(()) } @@ -5360,7 +5416,7 @@ async fn test_outgoing_plaintext_two_member_group() -> Result<()> { let chat = Chat::load_from_db(alice, msg.chat_id).await?; assert_eq!(chat.typ, Chattype::Group); - + alice.assert_warn("unencrypted message").await; Ok(()) } @@ -5599,6 +5655,9 @@ async fn test_small_unencrypted_group() -> Result<()> { let alice_bob_id = alice.add_or_lookup_address_contact_id(bob).await; add_contact_to_chat(alice, alice_chat_id, alice_bob_id).await?; send_text_msg(alice, alice_chat_id, "Hello!".to_string()).await?; + alice + .assert_warn("No good message identifying the chat found") + .await; let sent_msg = alice.pop_sent_msg().await; let bob_chat_id = bob.recv_msg(&sent_msg).await.chat_id; diff --git a/src/securejoin/securejoin_tests.rs b/src/securejoin/securejoin_tests.rs index 7434a94df8..a771207c81 100644 --- a/src/securejoin/securejoin_tests.rs +++ b/src/securejoin/securejoin_tests.rs @@ -29,25 +29,26 @@ enum SetupContactCase { #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_setup_contact_basic() { - test_setup_contact_ex(SetupContactCase::Normal).await + test_setup_contact_ex(SetupContactCase::Normal).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_setup_contact_wrong_alice_gossip() { - test_setup_contact_ex(SetupContactCase::WrongAliceGossip).await + let (alice, _) = test_setup_contact_ex(SetupContactCase::WrongAliceGossip).await; + alice.assert_warn("No self addr+pubkey gossip found").await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_setup_contact_alice_is_bot() { - test_setup_contact_ex(SetupContactCase::AliceIsBot).await + test_setup_contact_ex(SetupContactCase::AliceIsBot).await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_setup_contact_alice_has_name() { - test_setup_contact_ex(SetupContactCase::AliceHasName).await + test_setup_contact_ex(SetupContactCase::AliceHasName).await; } -async fn test_setup_contact_ex(case: SetupContactCase) { +async fn test_setup_contact_ex(case: SetupContactCase) -> (TestContext, TestContext) { let _n = TimeShiftFalsePositiveNote; let mut tcm = TestContextManager::new(); @@ -217,7 +218,7 @@ async fn test_setup_contact_ex(case: SetupContactCase) { .unwrap(); assert_eq!(handshake_msg, HandshakeMessage::Ignore); assert!(contact_bob.is_verified(&alice).await.unwrap()); - return; + return (alice, bob); } // Alice should not yet have Bob verified @@ -300,6 +301,8 @@ async fn test_setup_contact_ex(case: SetupContactCase) { let msg = get_chat_msg(&bob, bob_chat.get_id(), 0, 1).await; assert!(msg.is_info()); assert_eq!(msg.get_text(), messages_e2ee_info_msg(&bob)); + + (alice, bob) } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -307,6 +310,8 @@ async fn test_setup_contact_bad_qr() { let bob = TestContext::new_bob().await; let ret = join_securejoin(&bob.ctx, "not a qr code").await; assert!(ret.is_err()); + bob.assert_warn("Unsupported QR type").await; + bob.assert_error("QR process failed").await; } #[tokio::test(flavor = "multi_thread", worker_threads = 2)] @@ -791,6 +796,7 @@ First thread."#; let chat_id = msg.chat_id; assert!(get_securejoin_qr(&alice, Some(chat_id)).await.is_err()); + alice.assert_error("Can't generate QR code").await; Ok(()) } @@ -983,6 +989,13 @@ async fn test_parallel_setup_contact(bob_deletes_fiona_contact: bool) -> Result< let bob_alice_contact = Contact::get_by_id(bob, bob_alice_contact_id).await.unwrap(); assert_eq!(bob_alice_contact.is_verified(bob).await.unwrap(), true); + bob.assert_warn("Message does not match expected fingerprint") + .await; + if bob_deletes_fiona_contact { + bob.assert_warn("Message does not match expected fingerprint") + .await; + } + Ok(()) } @@ -1013,7 +1026,7 @@ async fn test_wrong_auth_token() -> Result<()> { let alice_bob_contact = alice.add_or_lookup_contact(bob).await; assert!(!alice_bob_contact.is_verified(alice).await?); - + alice.assert_warn("invalid auth code").await; Ok(()) } @@ -1377,6 +1390,10 @@ async fn test_qr_no_implicit_inviter_addition() -> Result<()> { let charlie_chat_contacts = chat::get_chat_contacts(charlie, charlie_chat_id).await?; assert_eq!(charlie_chat_contacts.len(), 2); + bob.assert_error("self not in group").await; + bob.assert_warn("the account is not part of the group/broadcast") + .await; + Ok(()) } @@ -1588,6 +1605,9 @@ async fn test_auth_token_is_synchronized() -> Result<()> { .unwrap(); assert_eq!(auth_count, 2); + bob.assert_warn("Could not find symmetric secret for session key") + .await; + bob.assert_warn("unencrypted message").await; Ok(()) } diff --git a/src/sql/sql_tests.rs b/src/sql/sql_tests.rs index da6d8f097d..d56c45efe9 100644 --- a/src/sql/sql_tests.rs +++ b/src/sql/sql_tests.rs @@ -99,6 +99,8 @@ async fn test_housekeeping_db_closed() { _ => {} } } + + t.assert_many(vec![(false, "no SQL connection", 17)]).await; } /// Regression test for a bug where housekeeping deleted drafts since their diff --git a/src/stats/stats_tests.rs b/src/stats/stats_tests.rs index 385892cf67..5dc8034683 100644 --- a/src/stats/stats_tests.rs +++ b/src/stats/stats_tests.rs @@ -254,7 +254,7 @@ async fn test_message_stats() -> Result<()> { expected.get_mut(&Chattype::Single).unwrap().verified += 1; check_stats(&send_and_read_stats(alice).await, &expected); - + alice.assert_warn("Missing securejoin source").await; Ok(()) } @@ -319,10 +319,12 @@ async fn test_stats_securejoin_sources() -> Result<()> { join_securejoin_with_ux_info(alice, &qr, Some(SecurejoinSource::InternalLink), None).await?; expected.internal_link += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin_with_ux_info(alice, &qr, Some(SecurejoinSource::ImageLoaded), None).await?; expected.image_loaded += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin_with_ux_info(alice, &qr, Some(SecurejoinSource::Scan), None).await?; expected.scan += 1; @@ -370,22 +372,27 @@ async fn test_stats_securejoin_uipaths() -> Result<()> { join_securejoin(alice, &qr).await?; expected.other += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin(alice, &qr).await?; expected.other += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin_with_ux_info(alice, &qr, None, Some(SecurejoinUiPath::NewContact)).await?; expected.new_contact += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin_with_ux_info(alice, &qr, None, Some(SecurejoinUiPath::NewContact)).await?; expected.new_contact += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; join_securejoin_with_ux_info(alice, &qr, None, Some(SecurejoinUiPath::QrIcon)).await?; expected.qr_icon += 1; check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; Ok(()) } @@ -461,6 +468,13 @@ async fn test_stats_securejoin_invites() -> Result<()> { }); check_stats(alice, &expected).await; + alice.assert_warn("Missing securejoin source").await; + alice.assert_warn("Missing securejoin source").await; + alice.assert_warn("Missing securejoin source").await; + alice.assert_warn("Missing securejoin source").await; + bob.assert_warn("missing key").await; + bob.assert_warn("unencrypted message").await; + Ok(()) } diff --git a/src/summary.rs b/src/summary.rs index 9f665f3867..9f9ca9dcbe 100644 --- a/src/summary.rs +++ b/src/summary.rs @@ -490,5 +490,6 @@ mod tests { msg.get_summary_text_without_prefix(ctx).await, "📎 foo.bar \u{2013} bla bla" ); // skipping prefix used for reactions summaries + d.assert_warn("Not a valid DeltaChat vCard").await; } } diff --git a/src/sync.rs b/src/sync.rs index 3f386bdea3..a9c58a24bb 100644 --- a/src/sync.rs +++ b/src/sync.rs @@ -695,6 +695,9 @@ mod tests { bob.recv_msg_trash(&sent_msg).await; assert!(!token::exists(&bob, token::Namespace::Auth, "testtoken").await?); + bob.assert_warn("missing key").await; + bob.assert_warn("unencrypted message").await; + Ok(()) } diff --git a/src/test_utils.rs b/src/test_utils.rs index f3bb9ef8b3..e19c6c2aef 100644 --- a/src/test_utils.rs +++ b/src/test_utils.rs @@ -1,9 +1,10 @@ //! Utilities to help writing tests. //! //! This private module is only compiled for test runs. + use std::collections::{BTreeMap, BTreeSet, HashSet}; use std::env::current_dir; -use std::fmt::Write; +use std::fmt::{Debug, Write}; use std::ops::{Deref, DerefMut}; use std::panic; use std::path::Path; @@ -36,7 +37,6 @@ use crate::context::Context; use crate::e2ee::EncryptHelper; use crate::events::{Event, EventEmitter, EventType, Events}; use crate::key::{self, DcKey, self_fingerprint}; -use crate::log::warn; use crate::login_param::EnteredLoginParam; use crate::message::{Message, MessageState, MsgId}; use crate::mimeparser::{MimeMessage, SystemMessage}; @@ -73,14 +73,12 @@ static CONTEXT_NAMES: LazyLock>> = /// occurred rather than grouped by context like would happen when you use separate /// [`TestContext`]s without managing your own [`LogSink`]. pub struct TestContextManager { - log_sink: LogSink, used_names: BTreeSet, } impl TestContextManager { pub fn new() -> Self { Self { - log_sink: LogSink::new(), used_names: BTreeSet::new(), } } @@ -89,7 +87,6 @@ impl TestContextManager { TestContext::builder() .configure_alice() .with_id_offset(1000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -98,7 +95,6 @@ impl TestContextManager { TestContext::builder() .configure_bob() .with_id_offset(2000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -107,7 +103,6 @@ impl TestContextManager { TestContext::builder() .configure_charlie() .with_id_offset(3000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -116,7 +111,6 @@ impl TestContextManager { TestContext::builder() .configure_dom() .with_id_offset(4000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -126,7 +120,6 @@ impl TestContextManager { TestContext::builder() .configure_elena() .with_id_offset(5000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -135,7 +128,6 @@ impl TestContextManager { TestContext::builder() .configure_fiona() .with_id_offset(6000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -146,7 +138,6 @@ impl TestContextManager { .with_key_pair(pqc_keypair()) .with_address("pqc@example.org".to_string()) .with_id_offset(7000) - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -154,7 +145,6 @@ impl TestContextManager { /// Creates a new unconfigured test account. pub async fn unconfigured(&mut self) -> TestContext { TestContext::builder() - .with_log_sink(self.log_sink.clone()) .build(Some(&mut self.used_names)) .await } @@ -163,12 +153,7 @@ impl TestContextManager { /// /// ========== `msg` goes here ========== pub fn section(&self, msg: &str) { - self.log_sink - .sender - .try_send(LogEvent::Section(msg.to_string())) - .expect( - "The events channel should be unbounded and not closed, so try_send() shouldn't fail", - ); + print_logevent(&LogEvent::Section(msg.to_string())); } /// - Let one TestContext send a message @@ -412,17 +397,6 @@ impl TestContextBuilder { self } - /// Attaches a [`LogSink`] to this [`TestContext`]. - /// - /// This is useful when using multiple [`TestContext`] instances in one test: it allows - /// using a single [`LogSink`] for both contexts. This shows the log messages in - /// sequence as they occurred rather than all messages from each context in a single - /// block. - pub fn with_log_sink(mut self, sink: LogSink) -> Self { - self.log_sink = Some(sink); - self - } - /// Adds an offset for chat-, message-, contact IDs. /// /// This makes it harder to accidentally mix up IDs from different accounts. @@ -487,15 +461,7 @@ pub struct TestContext { pub evtracker: EventTracker, - /// Reference to implicit [`LogSink`] so it is dropped together with the context. - /// - /// Only used if no explicit `log_sender` is passed into [`TestContext::new_internal`] - /// (which is assumed to be the sending end of a [`LogSink`]). - /// - /// This is a convenience in case only a single [`TestContext`] is used to avoid dealing - /// with [`LogSink`]. Never read, since the only purpose is to - /// control when Drop is invoked. - _log_sink: Option, + log_sink: LogSink, } impl TestContext { @@ -581,15 +547,15 @@ impl TestContext { .await .expect("failed to create context"); - let _log_sink = if let Some(log_sink) = log_sink { - // Subscribe existing LogSink and don't store reference to it. + let log_sink = if let Some(log_sink) = log_sink { + // Subscribe existing LogSink and store it inside the `TestContext`. log_sink.subscribe(ctx.get_event_emitter()); - None + log_sink } else { // Create new LogSink and store it inside the `TestContext`. let log_sink = LogSink::new(); log_sink.subscribe(ctx.get_event_emitter()); - Some(log_sink) + log_sink }; ctx.set_config(Config::SkipStartMessages, Some("1")) @@ -602,7 +568,7 @@ impl TestContext { ctx, dir, evtracker: EventTracker::new(evtracker_receiver), - _log_sink, + log_sink, } } @@ -895,8 +861,8 @@ ORDER BY id" .expect("add_or_lookup"); match modified { Modifier::None => (), - Modifier::Modified => warn!(&self.ctx, "Contact {} modified by TestContext", &addr), - Modifier::Created => warn!(&self.ctx, "Contact {} created by TestContext", &addr), + Modifier::Modified => info!(&self.ctx, "Contact {} modified by TestContext", &addr), + Modifier::Created => info!(&self.ctx, "Contact {} created by TestContext", &addr), } contact_id } @@ -1233,6 +1199,37 @@ ORDER BY id" self.set_config_bool(Config::ForceEncryption, false).await?; Ok(()) } + + /// Asserts a warning containing `pat` should be logged. + /// + /// Delegates to [`InnerLogSink::assert_warn`]. + pub async fn assert_warn(&self, pat: &str) { + self.log_sink.assert_warn(pat).await + } + + /// Asserts an error containing `pat` should be logged. + /// + /// Delegates to [`InnerLogSink::assert_error`]. + pub async fn assert_error(&self, pat: &str) { + self.log_sink.assert_error(pat).await + } + + /// Asserts many errors or warning should be logged, that can happen in any order. + /// + /// The first part of the passed tuples controls whether the log should be a warning (`false`), + /// or an error (`true`). + /// The second part of the tuple is the pattern used for matching. + /// The last part of the tuple controls how many times the pattern must be hit. + /// + /// # Important + /// + /// Order of assertions matters: if a log can be matched by multiple patterns, + /// the first one takes precedence. + /// + /// Delegates to [`InnerLogSink::assert_many`]. + pub async fn assert_many(&self, assertions: Vec<(bool, &str, usize)>) { + self.log_sink.assert_many(assertions).await + } } pub async fn encrypt_raw_message( @@ -1337,6 +1334,7 @@ impl Drop for TestContext { } } +#[derive(Debug, Clone)] pub enum LogEvent { /// Logged event. Event(Event), @@ -1345,17 +1343,29 @@ pub enum LogEvent { Section(String), } +impl LogEvent { + pub fn is_warn(&self) -> bool { + if let Self::Event(event) = self { + event.is_warn() + } else { + false + } + } + + pub fn is_error(&self) -> bool { + if let Self::Event(event) = self { + event.is_error() + } else { + false + } + } +} + /// A receiver of [`Event`]s which will log the events to the captured test stdout. /// /// Tests redirect the stdout of the test thread and capture this, showing the captured /// stdout if the test fails. This means printing log messages must be done on the thread /// of the test itself and not from a spawned task. -/// -/// This sink achieves this by printing the events, in the order received, at the time it is -/// dropped. Thus to use you must only make sure this sink is dropped in the test itself. -/// -/// To use this create an instance using [`LogSink::new`] and then use the -/// [`TestContextBuilder::with_log_sink`] or use [`TestContextManager`]. #[derive(Debug, Clone, Default)] pub struct LogSink(Arc); @@ -1376,6 +1386,7 @@ impl Deref for LogSink { #[derive(Debug)] pub struct InnerLogSink { + /// Log events receiver. events: Receiver, /// Sender side of the log receiver. @@ -1403,16 +1414,122 @@ impl InnerLogSink { let sender = self.sender.clone(); task::spawn(async move { while let Some(event) = event_emitter.recv().await { - sender.try_send(LogEvent::Event(event.clone())).ok(); + let log_event = LogEvent::Event(event.clone()); + print_logevent(&log_event); + sender.try_send(log_event).ok(); } }); } + + async fn assert(&self, is_error: bool, pat: &str) { + while let Ok(Ok(event)) = + tokio::time::timeout(Duration::from_secs(1), self.events.recv()).await + { + if Self::assert_inner(event, is_error, pat) { + return; + } + } + if is_error { + panic!("Expected an error log.") + } else { + panic!("Expected a warning log.") + } + } + + fn assert_inner(log_event: LogEvent, is_error: bool, pat: &str) -> bool { + if let LogEvent::Event(e) = &log_event + && let Some(log) = match is_error { + false => e.typ.get_warn(), + true => e.typ.get_error(), + } + { + assert!(log.contains(pat), "'{log}' does not contain '{pat}'."); + true + } else { + if is_error { + assert!( + !log_event.is_warn(), + "Expected a warning log, but found an error log instead.", + ); + } else { + assert!( + !log_event.is_error(), + "Expected an error log, but found a warning log instead.", + ); + } + false + } + } + + /// Asserts many errors or warning should be logged, that can happen in any order. + /// + /// The first part of the passed tuples controls whether the log should be a warning (`false`), + /// or an error (`true`). + /// The second part of the tuple is the pattern used for matching. + /// The last part of the tuple controls how many times the pattern must be hit. + /// + /// # Important + /// + /// Order of assertions matters: if a log can be matched by multiple patterns, + /// the first one takes precedence. + pub async fn assert_many(&self, mut assertions: Vec<(bool, &str, usize)>) { + 'events: while let Ok(Ok(event)) = + tokio::time::timeout(Duration::from_secs(1), self.events.recv()).await + { + let is_error = if event.is_warn() { + false + } else if event.is_error() { + true + } else { + // neither, skip + continue 'events; + }; + + 'assertions: for (assert_is_error, pat, count) in &mut assertions { + if *assert_is_error != is_error || *count == 0 { + continue 'assertions; + } + if let LogEvent::Event(e) = &event + && let Some(log) = match is_error { + false => e.typ.get_warn(), + true => e.typ.get_error(), + } + && log.contains(*pat) + { + *count = count.saturating_sub(1); + continue 'events; + } + } + panic!("Unexpected log event: {event:?}.") + } + + for (is_error, pat, count_left) in assertions { + if count_left > 0 { + if is_error { + panic!("Expected an error log matching: '{pat}'"); + } else { + panic!("Expected a warning log matching: '{pat}'"); + } + } + } + } + + /// Asserts that a warning containing `pat` should be logged. + pub async fn assert_warn(&self, pat: &str) { + self.assert(false, pat).await + } + + /// Asserts that an error containing `pat` should be logged. + pub async fn assert_error(&self, pat: &str) { + self.assert(true, pat).await + } } impl Drop for InnerLogSink { fn drop(&mut self) { while let Ok(event) = self.events.try_recv() { - print_logevent(&event); + assert!(!event.is_warn(), "Logged an unexpected warning: {event:?}"); + assert!(!event.is_error(), "Logged an unexpected error: {event:?}"); } if std::env::var("DELTACHAT_SAVE_TMP_DB").is_err() { eprintln!( diff --git a/src/tests/aeap.rs b/src/tests/aeap.rs index 5e61c5c1e3..dc2dbb1272 100644 --- a/src/tests/aeap.rs +++ b/src/tests/aeap.rs @@ -218,6 +218,11 @@ async fn test_aeap_replay_attack() -> Result<()> { assert!(chat::is_contact_in_chat(&bob, group, bob_alice_contact).await?); assert!(!chat::is_contact_in_chat(&bob, group, bob_fiona_contact).await?); + bob.assert_warn(r#"Autocrypt header address "alice@example.org" is not "fiona@example.net""#) + .await; + bob.assert_warn("From header in encrypted part doesn't match the outer one") + .await; + Ok(()) } diff --git a/src/tests/pre_messages/forward_and_save.rs b/src/tests/pre_messages/forward_and_save.rs index feb3a72c89..f475f26b13 100644 --- a/src/tests/pre_messages/forward_and_save.rs +++ b/src/tests/pre_messages/forward_and_save.rs @@ -93,7 +93,7 @@ async fn test_receive_both() -> Result<()> { let mut tcm = TestContextManager::new(); let alice = &tcm.alice().await; let bob = &tcm.bob().await; - let alice_chat_id = alice.create_group_with_members("", &[bob]).await; + let alice_chat_id = alice.create_group_with_members("group", &[bob]).await; let (pre_message, post_message, alice_msg_id) = send_large_file_message(alice, alice_chat_id, Viewtype::File, &vec![0u8; 200_000]).await?; diff --git a/src/tests/pre_messages/legacy.rs b/src/tests/pre_messages/legacy.rs index 0674b02524..b553a26586 100644 --- a/src/tests/pre_messages/legacy.rs +++ b/src/tests/pre_messages/legacy.rs @@ -52,6 +52,6 @@ async fn test_download_stub_message() -> Result<()> { assert_eq!(msg.download_state(), DownloadState::Available); assert_eq!(msg.get_subject(), "foo"); assert!(msg.get_text().contains("[97.66 KiB message]")); - + t.assert_warn("unencrypted message").await; Ok(()) } diff --git a/src/tests/pre_messages/receiving.rs b/src/tests/pre_messages/receiving.rs index ee1be42982..32b51cd17f 100644 --- a/src/tests/pre_messages/receiving.rs +++ b/src/tests/pre_messages/receiving.rs @@ -138,7 +138,7 @@ async fn test_receive_webxdc() -> Result<()> { let mut tcm = TestContextManager::new(); let alice = &tcm.alice().await; let bob = &tcm.bob().await; - let alice_group_id = alice.create_group_with_members("", &[bob]).await; + let alice_group_id = alice.create_group_with_members("group", &[bob]).await; let (pre_msg, post_msg, _) = send_large_file_message( alice, @@ -310,7 +310,7 @@ async fn pre_msg_mdn_before_sending_full(text: &str) -> Result<()> { let mut tcm = TestContextManager::new(); let alice = &tcm.alice().await; let bob = &tcm.bob().await; - let alice_chat_id = alice.create_group_with_members("", &[bob]).await; + let alice_chat_id = alice.create_group_with_members("group", &[bob]).await; let file_bytes = include_bytes!("../../../test-data/image/screenshot.gif"); let mut msg = Message::new(Viewtype::Image); @@ -357,7 +357,9 @@ async fn test_post_msg_bad_sender() -> Result<()> { let alice = &tcm.alice().await; let bob = &tcm.bob().await; let fiona = &tcm.fiona().await; - let chat_id_alice = alice.create_group_with_members("", &[bob, fiona]).await; + let chat_id_alice = alice + .create_group_with_members("group", &[bob, fiona]) + .await; let file_bytes = include_bytes!("../../../test-data/image/screenshot.gif"); let mut msg_alice = Message::new(Viewtype::Image); @@ -383,6 +385,8 @@ async fn test_post_msg_bad_sender() -> Result<()> { bob.recv_msg_trash(&post_msg_alice).await; let msg_bob = Message::load_from_db(bob, msg_bob.id).await?; assert_eq!(msg_bob.download_state, DownloadState::Done); + + bob.assert_warn("Bad sender").await; Ok(()) } @@ -392,7 +396,9 @@ async fn test_lost_pre_msg_vs_new_member() -> Result<()> { let alice = &tcm.alice().await; let bob = &tcm.bob().await; let fiona = &tcm.fiona().await; - let chat_id_alice = alice.create_group_with_members("", &[bob, fiona]).await; + let chat_id_alice = alice + .create_group_with_members("group", &[bob, fiona]) + .await; let file_bytes = include_bytes!("../../../test-data/image/screenshot.gif"); let mut msg_alice = Message::new(Viewtype::Image); @@ -406,8 +412,11 @@ async fn test_lost_pre_msg_vs_new_member() -> Result<()> { chat_id_bob.accept(bob).await?; let sent = bob.send_text(chat_id_bob, "Hi all").await; + bob.assert_warn("Missing key for fiona@example.net").await; alice.recv_msg(&sent).await; fiona.recv_msg_trash(&sent).await; // Undecryptable message + fiona.assert_warn("decryption failed").await; + fiona.assert_warn("unencrypted message").await; Ok(()) } @@ -565,6 +574,9 @@ async fn test_full_download_after_trashed() -> Result<()> { let msg = Message::load_from_db_optional(bob, alice_msg.id).await?; assert!(msg.is_none()); + alice + .assert_warn("Pre-message was not downloaded yet so treat as normal message") + .await; Ok(()) } @@ -755,6 +767,11 @@ async fn test_webxdc_updates_in_post_message_after_deleted_pre_message() -> Resu .is_none() ); + bob.assert_warn("Pre-message was not downloaded yet so treat as normal message") + .await; + bob.assert_warn("Received webxdc update, but cannot assign it to message") + .await; + Ok(()) } diff --git a/src/tests/verified_chats.rs b/src/tests/verified_chats.rs index fae8b3974b..07557b45ef 100644 --- a/src/tests/verified_chats.rs +++ b/src/tests/verified_chats.rs @@ -57,6 +57,7 @@ async fn check_verified_single_chat_protection_not_broken(by_classical_email: bo .await .unwrap() .unwrap(); + alice.assert_warn("unencrypted message").await; let contact = alice.add_or_lookup_contact(&bob).await; assert_eq!(contact.is_verified(&alice).await.unwrap(), true); assert_verified(&alice, &bob).await; @@ -598,6 +599,13 @@ async fn test_verified_lost_member_added() -> Result<()> { let result = send_msg(bob, bob_chat_id, &mut msg).await; assert!(result.is_err()); + bob.assert_warn("Missing key for fiona@example.net").await; + fiona.assert_warn("missing key").await; + fiona.assert_warn("unencrypted message").await; + bob.assert_warn("Missing key for fiona@example.net").await; + bob.assert_warn(r#"No recipient keys are available, cannot encrypt to ["fiona@example.net"]"#) + .await; + Ok(()) } diff --git a/src/tools/tools_tests.rs b/src/tools/tools_tests.rs index 77bde4fbf5..596ad19b91 100644 --- a/src/tools/tools_tests.rs +++ b/src/tools/tools_tests.rs @@ -328,6 +328,7 @@ async fn test_file_handling() { assert!(delete_file(context, Path::new(fn0)).await.is_ok()); assert!(!file_exist!(context, &fn0)); + t.assert_warn("refusing to delete non-file").await; } #[test] diff --git a/src/webxdc/webxdc_tests.rs b/src/webxdc/webxdc_tests.rs index 12f0b9e135..9a3fb43264 100644 --- a/src/webxdc/webxdc_tests.rs +++ b/src/webxdc/webxdc_tests.rs @@ -90,7 +90,7 @@ async fn test_send_webxdc_instance() -> Result<()> { let mut instance = Message::new(Viewtype::Webxdc); instance.set_file_from_bytes(&t, "index.html", b"ola!", None)?; assert!(send_msg(&t, chat_id, &mut instance).await.is_err()); - + t.assert_warn("cannot be opened as zip-file").await; Ok(()) } @@ -119,7 +119,8 @@ async fn test_send_invalid_webxdc() -> Result<()> { None, )?; assert!(send_msg(&t, chat_id, &mut instance).await.is_err()); - + t.assert_warn("cannot be opened as zip-file").await; + t.assert_warn("cannot be opened as zip-file").await; Ok(()) } @@ -1298,6 +1299,7 @@ async fn test_get_webxdc_info() -> Result<()> { let result = msg.get_webxdc_info(&t).await; assert!(result.is_err()); + t.assert_warn("empty name given in manifest").await; Ok(()) } @@ -1695,6 +1697,7 @@ async fn test_webxdc_reject_updates_from_non_groupmembers() -> Result<()> { status, r#"[{"payload":7,"info":"i","summary":"s","serial":1,"max_serial":1}]"# ); + alice.assert_warn("not a member of chat").await; Ok(()) }