Development

Working on the Pueue codebase

How to find and debug flaking tests

Sometimes tests can fail unpredictably. This usually happens because the test itself uses asynchronous actions to configure pueue, but the actions triggered then complete in a different order from what was expected. You can usually solve such issues by making use of debug logging statements already present in the codebase.

First, you'll have to figure out what tests could be flaky. To do so, run the test suite in a continuous loop; preferably with cargo nextest as that's the faster test runner. Use the following command-line switches to minimise output for runs without test failures:

while cargo nextest run --workspace --hide-progress-bar --status-level=fail
do :; done

You can, however, do the same with the default cargo test command:

while cargo test --quiet
do :; done

The loop exits when a test fails, indicating that that test could be flaking.

Once a flaking test has been identified, add a test filter to the cargo nextest / cargo test command line to focus on that specific test, add the RUST_LOG=debug environment variable to to ensure you get plenty of log output when a failure happens. Note: this requires that the specific test has been set up to configure the logging subsystem whenever it runs. Not all tests have been updated to do this yet, so check if the test in question is using use the test-log macro, and if not, update the test annotation before trying to reproduce the issue.

The daemon::edit::test_edit_flow is one such test that already is set up to output logs when run. As it is an asynchronous Tokio test, it uses the test_log::test macro as a wrapper:

use test_log::test;

// ...

#[test(tokio::test(flavor = "multi_thread", worker_threads = 2))]
/// Test if adding a normal task works as intended.
async fn test_edit_flow() -> Result<()> {

Then, to run daemon::edit::test_edit_flow in a loop, use the following shell command:

while RUST_LOG=debug cargo nextest run --workspace --hide-progress-bar --status-level=fail \
    daemon::edit::test_edit_flow
do :; done

The cargo test equivalent is:

while RUST_LOG=debug cargo test --workspace --quiet \
    --test daemon_tests daemon::edit::test_edit_flow
do :; done

When you next hit a failure, you should have a plethora of information as to what pueue was doing up to that point.