Skip to content

test: fix flaky chatlist_events test test_update_after_ephemeral_messages #5471

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.

Sign up for GitHub

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

Merged
link2xt merged 3 commits into from
Apr 18, 2024
Merged

test: fix flaky chatlist_events test test_update_after_ephemeral_messages #5471

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
caa81fa
test: fix flaky chatlist_events test test_update_after_ephemeral_mess…
link2xt Apr 18, 2024
c173d93
test: make EventTracker.clear_events() reliable
link2xt Apr 18, 2024
a20e986
ci: allow older versions of Sphinx than 7.2.6
link2xt Apr 18, 2024
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
2 changes: 1 addition & 1 deletion python/tox.ini
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ commands =
changedir=doc
deps =
# Pinned version, workaround for <https://github.com/breathe-doc/breathe/issues/981>
sphinx==7.2.6
sphinx<7.3
breathe
sphinx_rtd_theme
commands =
Expand Down
71 changes: 39 additions & 32 deletions src/events/chatlist_events.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -181,7 +181,7 @@ mod test_chatlist_events {
.await?;
set_muted(&bob, bob_chat.id, MuteDuration::Forever).await?;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;

let sent_msg = alice.send_text(chat.id, "moin2").await;
bob.recv_msg(&sent_msg).await;
Expand Down Expand Up @@ -216,7 +216,7 @@ mod test_chatlist_events {
let sent_msg = alice.send_text(chat.id, "moin2").await;
bob.recv_msg(&sent_msg).await;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
chat::marknoticed_chat(&bob, DC_CHAT_ID_ARCHIVED_LINK).await?;
wait_for_chatlist_specific_item(&bob, DC_CHAT_ID_ARCHIVED_LINK).await;

Expand All @@ -233,7 +233,7 @@ mod test_chatlist_events {
let sent_msg = alice.send_text(alice_to_bob_chat.id, "hello").await;
bob.recv_msg(&sent_msg).await;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
// set alice name then receive messagefrom her with bob
alice.set_config(Config::Displayname, Some("Alice")).await?;
let sent_msg = alice
Expand All @@ -245,7 +245,7 @@ mod test_chatlist_events {

wait_for_chatlist_all_items(&bob).await;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
// set name
let addr = alice_on_bob.get_addr();
Contact::create(&bob, "Alice2", addr).await?;
Expand All @@ -266,7 +266,7 @@ mod test_chatlist_events {
let sent_msg = alice.send_text(alice_to_bob_chat.id, "hello").await;
bob.recv_msg(&sent_msg).await;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
// set alice avatar then receive messagefrom her with bob
let file = alice.dir.path().join("avatar.png");
let bytes = include_bytes!("../../test-data/image/avatar64x64.png");
Expand All @@ -292,7 +292,7 @@ mod test_chatlist_events {
let alice = tcm.alice().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
chat.delete(&alice).await?;
wait_for_chatlist(&alice).await;
Ok(())
Expand All @@ -303,7 +303,7 @@ mod test_chatlist_events {
async fn test_create_group_chat() -> Result<()> {
let mut tcm = TestContextManager::new();
let alice = tcm.alice().await;
alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;
wait_for_chatlist_and_specific_item(&alice, chat).await;
Ok(())
Expand All @@ -314,7 +314,7 @@ mod test_chatlist_events {
async fn test_create_broadcastlist() -> Result<()> {
let mut tcm = TestContextManager::new();
let alice = tcm.alice().await;
alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
create_broadcast_list(&alice).await?;
wait_for_chatlist(&alice).await;
Ok(())
Expand All @@ -327,11 +327,11 @@ mod test_chatlist_events {
let alice = tcm.alice().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
chat::set_muted(&alice, chat, MuteDuration::Forever).await?;
wait_for_chatlist_specific_item(&alice, chat).await;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
chat::set_muted(&alice, chat, MuteDuration::NotMuted).await?;
wait_for_chatlist_specific_item(&alice, chat).await;

Expand All @@ -352,7 +352,7 @@ mod test_chatlist_events {
.unwrap(),
);
chat::set_muted(&alice, chat, mute_duration).await?;
alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
SystemTime::shift(Duration::from_secs(3));
wait_for_chatlist_specific_item(&alice, chat).await;

Expand All @@ -366,7 +366,7 @@ mod test_chatlist_events {
let alice = tcm.alice().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
chat::set_chat_name(&alice, chat, "New Name").await?;
wait_for_chatlist_specific_item(&alice, chat).await;

Expand All @@ -380,7 +380,7 @@ mod test_chatlist_events {
let alice = tcm.alice().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
let file = alice.dir.path().join("avatar.png");
let bytes = include_bytes!("../../test-data/image/avatar64x64.png");
tokio::fs::write(&file, bytes).await?;
Expand All @@ -405,7 +405,7 @@ mod test_chatlist_events {
wait_for_chatlist_specific_item(&bob, chat_id_for_bob).await;
chat_id_for_bob.accept(&bob).await?;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
chat::set_chat_name(&alice, chat, "New Name").await?;
let sent_msg = alice.send_text(chat, "Hello").await;
bob.recv_msg(&sent_msg).await;
Expand All @@ -426,7 +426,7 @@ mod test_chatlist_events {
let sent_msg = alice.send_text(chat, "Hello").await;
let chat_id_for_bob = bob.recv_msg(&sent_msg).await.chat_id;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
chat_id_for_bob.accept(&bob).await?;
wait_for_chatlist_specific_item(&bob, chat_id_for_bob).await;

Expand All @@ -445,7 +445,7 @@ mod test_chatlist_events {
let sent_msg = alice.send_text(chat, "Hello").await;
let chat_id_for_bob = bob.recv_msg(&sent_msg).await.chat_id;

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
chat_id_for_bob.block(&bob).await?;
wait_for_chatlist(&bob).await;

Expand All @@ -460,7 +460,7 @@ mod test_chatlist_events {
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;
let message = chat::send_text_msg(&alice, chat, "Hello World".to_owned()).await?;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
message::delete_msgs(&alice, &[message]).await?;
wait_for_chatlist_specific_item(&alice, chat).await;

Expand All @@ -485,7 +485,7 @@ mod test_chatlist_events {
let chat_id_for_bob = bob.recv_msg(&sent_msg).await.chat_id;
assert!(chat_id_for_bob.get_fresh_msg_cnt(&bob).await? >= 1);

bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
chat::marknoticed_chat(&bob, chat_id_for_bob).await?;
wait_for_chatlist_specific_item(&bob, chat_id_for_bob).await;

Expand All @@ -500,29 +500,36 @@ mod test_chatlist_events {
let contact_id = Contact::create(&alice, "example", "example@example.com").await?;
let _ = ChatId::create_for_contact(&alice, contact_id).await;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
Contact::block(&alice, contact_id).await?;
wait_for_chatlist(&alice).await;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
Contact::unblock(&alice, contact_id).await?;
wait_for_chatlist(&alice).await;

Ok(())
}

/// ephemeral / disappearing messages
/// Tests that expired disappearing message
/// produces events about chatlist being modified.
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn test_update_after_ephemeral_messages() -> Result<()> {
let mut tcm = TestContextManager::new();
let alice = tcm.alice().await;
let chat = create_group_chat(&alice, ProtectionStatus::Protected, "My Group").await?;
chat.set_ephemeral_timer(&alice, crate::ephemeral::Timer::Enabled { duration: 1 })
chat.set_ephemeral_timer(&alice, crate::ephemeral::Timer::Enabled { duration: 60 })
.await?;
alice
Copy link
Collaborator

@iequidoo iequidoo Apr 18, 2024

Choose a reason for hiding this comment

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

Is this necessary? Maybe not bad to check though

Copy link
Collaborator Author

@link2xt link2xt Apr 18, 2024

Choose a reason for hiding this comment

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

This is to ensure we consume all events up to this one, including all chatlist events related to creation of group chat. Otherwise we may these events for events that we expect after deletion of ephemeral message. Better consume as many events as we can reliably expect as possible to have "checkpoints".

.evtracker
.get_matching(|evt| matches!(evt, EventType::ChatEphemeralTimerModified { .. }))
.await;

let _ = chat::send_text_msg(&alice, chat, "Hello".to_owned()).await?;
wait_for_chatlist_and_specific_item(&alice, chat).await;

alice.evtracker.clear_events();
SystemTime::shift(Duration::from_secs(3));
SystemTime::shift(Duration::from_secs(70));
crate::ephemeral::delete_expired_messages(&alice, crate::tools::time()).await?;
wait_for_chatlist_and_specific_item(&alice, chat).await;

Ok(())
Expand All @@ -540,7 +547,7 @@ Content-Type: text/plain; charset=utf-8; format=flowed; delsp=no

First thread."#;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
receive_imf(&alice, mime, false).await?;
wait_for_chatlist(&alice).await;

Expand All @@ -561,34 +568,34 @@ First thread."#;
let qr = get_securejoin_qr(&alice.ctx, Some(alice_chatid)).await?;

// Step 2: Bob scans QR-code, sends vg-request
bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
let bob_chatid = join_securejoin(&bob.ctx, &qr).await?;
wait_for_chatlist(&bob).await;

let sent = bob.pop_sent_msg().await;

// Step 3: Alice receives vg-request, sends vg-auth-required
alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
alice.recv_msg_trash(&sent).await;

let sent = alice.pop_sent_msg().await;

// Step 4: Bob receives vg-auth-required, sends vg-request-with-auth
bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
bob.recv_msg_trash(&sent).await;
wait_for_chatlist_and_specific_item(&bob, bob_chatid).await;

let sent = bob.pop_sent_msg().await;

// Step 5+6: Alice receives vg-request-with-auth, sends vg-member-added
alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
alice.recv_msg_trash(&sent).await;
wait_for_chatlist_and_specific_item(&alice, alice_chatid).await;

let sent = alice.pop_sent_msg().await;

// Step 7: Bob receives vg-member-added
bob.evtracker.clear_events();
bob.evtracker.clear_events().await;
bob.recv_msg(&sent).await;
wait_for_chatlist_and_specific_item(&bob, bob_chatid).await;

Expand All @@ -610,7 +617,7 @@ First thread."#;
let message = Message::load_from_db(&alice, msg_id).await?;
assert_eq!(message.get_state(), MessageState::OutDelivered);

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
chat::resend_msgs(&alice, &[msg_id]).await?;
wait_for_chatlist_specific_item(&alice, chat).await;

Expand All @@ -626,7 +633,7 @@ First thread."#;
let msg_id = chat::send_text_msg(&alice, chat, "Hello".to_owned()).await?;
let _ = alice.pop_sent_msg().await;

alice.evtracker.clear_events();
alice.evtracker.clear_events().await;
reaction::send_reaction(&alice, msg_id, "👍").await?;
let _ = alice.pop_sent_msg().await;
wait_for_chatlist_specific_item(&alice, chat).await;
Expand Down
13 changes: 10 additions & 3 deletions src/test_utils.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1025,9 +1025,16 @@ impl EventTracker {
.await;
}

/// Clears event queue
pub fn clear_events(&self) {
while self.try_recv().is_ok() {}
/// Clears event queue.
///
/// This spends 1 second instead of using `try_recv`
/// to avoid accidentally leaving an event that
/// was emitted right before calling `clear_events()`.
///
/// Avoid using this function if you can
/// by waiting for specific events you expect to receive.
pub async fn clear_events(&self) {
while let Ok(_ev) = tokio::time::timeout(Duration::from_secs(1), self.recv()).await {}
Copy link
Collaborator

@iequidoo iequidoo Apr 18, 2024

Choose a reason for hiding this comment

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

Can it be achieved by emitting a special test event and then waiting for it? Or there may be events that are emitted asynchronously?

Copy link
Collaborator Author

@link2xt link2xt Apr 18, 2024

Choose a reason for hiding this comment

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

The problem is that this task may simply not get resources and move events too slowly:
https://github.com/deltachat/deltachat-core-rust/blob/65822e53e669900d21f2c361458c1aa61851f480/src/test_utils.rs#L367-L376

Better way would be to get rid of this task so event cannot be in the process of being moved from one channel to another by the time we call clear_events(). But I don't know how much refactoring it is.

Copy link
Collaborator Author

@link2xt link2xt Apr 18, 2024

Choose a reason for hiding this comment

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

Actually it is a problem also in cases when test crashes/panics, this may lose events and you don't get them in printout then. Maybe makes sense to file it as a bug. If not for this task, clear_events would work reliably even without 1 second timeout.

Copy link
Collaborator Author

@link2xt link2xt Apr 20, 2024

Choose a reason for hiding this comment

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

There is now a PR #5478 with a fix for Rust clear_events.
For Python we indeed need a special event and wait for it, this is going to be implemented in #5477

}
}

Expand Down