chatmail / chatmail/core

Flaky `context::context_tests::test_cache_is_cleared_when_io_is_started`

Open
#8,671 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Rust
Stars
929
Forks
143
Avg merge
1d 20h
Merged PRs (30d)
53

Description

This is not the first time `test_cache_is_cleared_when_io_is_started` fails reporting that some table does not exist:
```
FAIL [ 0.446s] ( 301/1173) deltachat context::context_tests::test_cache_is_cleared_when_io_is_started
stdout ───

running 1 test
alice INFO: src/config.rs:770: Creating a pseudo configured account which will not be able to send or receive messages. Only meant for tests!
alice Received Event { id: 1671130952, typ: AccountsItemChanged }
alice INFO: src/scheduler.rs:73: starting IO
alice INFO: src/scheduler.rs:352: Starting inbox loop.
alice INFO: src/scheduler.rs:372: Transport 1: Preparing new IMAP session for inbox.
alice INFO: src/imap.rs:295: Connecting to IMAP server.
alice Received Event { id: 1671130952, typ: ConnectivityChanged }
alice Received Event { id: 1671130952, typ: ConnectivityChanged }
alice WARN: src/scheduler.rs:378: Transport 1: Failed to prepare inbox connection: No IMAP connection candidates provided.
alice INFO: src/scheduler.rs:372: Transport 1: Preparing new IMAP session for inbox.
alice WARN: src/imap.rs:276: IMAP got rate limited, waiting for 0h 0m 1s until can connect.

========== Chats of alice: ==========

alice INFO: src/scheduler.rs:559: Starting SMTP loop.
alice INFO: src/scheduler.rs:740: scheduler is running
alice Received Event { id: 1671130952, typ: ConnectivityChanged }
alice INFO: src/smtp.rs:558: Selected rows from SMTP queue: [].
alice INFO: src/scheduler.rs:602: SMTP fake idle started.
alice Received Event { id: 1671130952, typ: ConnectivityChanged }
alice INFO: src/scheduler.rs:644: SMTP has no messages to retry, waiting for interrupt.
alice WARN: src/ephemeral.rs:569: Can't calculate next ephemeral timeout: no such table: msgs
alice INFO: src/location.rs:711: Location loop is waiting for 24h 0m 0s or interrupt
alice INFO: src/contact.rs:2149: Recently seen loop waiting for 24h 0m 0s or interrupt
alice WARN: src/ephemeral.rs:578: Can't calculate timestamp of the next message expiration: failed to fetch raw config: delete_device_after
alice INFO: src/ephemeral.rs:609: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
test context::context_tests::test_cache_is_cleared_when_io_is_started ... FAILED

failures:

failures:
context::context_tests::test_cache_is_cleared_when_io_is_started

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 1134 filtered out; finished in 0.42s

stderr ───

thread 'context::context_tests::test_cache_is_cleared_when_io_is_started' (9973) panicked at src/test_utils.rs:1475:13:
Logged an unexpected warning: Event { id: 1671130952, typ: Warning("src/ephemeral.rs:569: Can't calculate next ephemeral timeout: no such table: msgs") }
stack backtrace:
0: __rustc::rust_begin_unwind
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/std/src/panicking.rs:679:5
1: core::panicking::panic_fmt
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/panicking.rs:80:14
2: ::drop
at ./src/test_utils.rs:1467:13
3: core::ptr::drop_glue::
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ptr/mod.rs:823:1
4: core::ptr::drop_in_place::
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ptr/mod.rs:818:14
5: >::drop_slow
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/alloc/src/sync.rs:2143:18
6: as core::ops::drop::Drop>::drop
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/alloc/src/sync.rs:2877:18
7: core::ptr::drop_glue::>
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ptr/mod.rs:823:1
8: core::ptr::drop_glue::
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ptr/mod.rs:823:1
9: core::ptr::drop_glue::
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ptr/mod.rs:823:1
10: deltachat::context::context_tests::test_cache_is_cleared_when_io_is_started::{closure#0}
at ./src/context/context_tests.rs:631:1
11: >> as core::future::future::Future>::poll
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/future/future.rs:133:9
12: ::block_on::>>>::{closure#0}
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/park.rs:284:71
13: tokio::task::coop::with_budget::>, ::block_on>>>::{closure#0}>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/task/coop/mod.rs:167:5
14: tokio::task::coop::budget::>, ::block_on>>>::{closure#0}>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/task/coop/mod.rs:133:5
15: ::block_on::>>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/park.rs:284:31
16: ::block_on::>>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/context/blocking.rs:66:14
17: ::block_on::>>>::{closure#0}
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/scheduler/multi_thread/mod.rs:92:22
18: tokio::runtime::context::runtime::enter_runtime::<::block_on>>>::{closure#0}, core::result::Result<(), anyhow::Error>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/context/runtime.rs:65:16
19: ::block_on::>>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/scheduler/multi_thread/mod.rs:91:9
20: ::block_on_inner::>>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/runtime.rs:376:50
21: ::block_on::>>>
at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/runtime.rs:343:18
22: deltachat::context::context_tests::test_cache_is_cleared_when_io_is_started
at ./src/context/context_tests.rs:630:7
23: deltachat::context::context_tests::test_cache_is_cleared_when_io_is_started::{closure#0}
at ./src/context/context_tests.rs:598:56
24: >::call_once
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ops/function.rs:250:5
25: core::result::Result<(), alloc::string::String> as core::ops::function::FnOnce<()>>::call_once
at /rustc/88d9e12ae178fab0fb5cc050a94da85685d449ea/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

Cancelling due to test failure: 3 tests still running
PASS [ 0.097s] ( 302/1173) deltachat context::context_tests::test_get_fresh_msgs_and_muted_until
PASS [ 1.485s] ( 303/1173) deltachat context::context_tests::test_context_change_passphrase
PASS [ 1.877s] ( 304/1173) deltachat context::context_tests::test_check_passphrase
────────────
Summary [ 29.593s] 304/1173 tests run: 303 passed, 1 failed, 1 skipped
FAIL [ 0.446s] ( 301/1173) deltachat context::context_tests::test_cache_is_cleared_when_io_is_started
```

Example run is at https://github.com/chatmail/core/actions/runs/33870825872/job/101016136283?pr=8667

Contributor guide

Open the contributing guide

Research direction

Start with src/context/context_tests.rs and run context::context_tests::test_cache_is_cleared_when_io_is_started repeatedly. Follow the startup logs into src/ephemeral.rs, especially the warnings at lines 569 and 578, and inspect the test log handling in src/test_utils.rs. Done means the test no longer reports a missing msgs table or other unexpected warnings across repeated runs.

Written by the indexing model from the issue text.

Assessment

Tech stack
rust
Domain
testing
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
55/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.