Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Significant Slowdown in Test Execution with nextest and llvm-cov #376

Open
seanpianka opened this issue Jul 13, 2024 · 1 comment
Open
Labels
C-question Category: A question

Comments

@seanpianka
Copy link

Description

This issue occurs with numerous tests ran within a suite of 415 other tests. The vast majority of these tests are of the same complexity as the test shown below (i.e.: simple methods which set a boolean field from false to true and assert it as such).

Using nextest with llvm-cov significantly slows test execution. A simple test takes over 42 seconds with coverage enabled, compared to under one second without it. The process to generate the line coverage data seems to be placing my CI runner's host under significant memory or I/O load.

Test Example

#[test]
fn test_auth_req_schema_serialize() {
    let auth_req = Authenticate {
        method: AuthenticateMethod::Password(UserPassAuthenticate {
            email: "sadf.com".to_string(),
            password: "password".to_string(),
        }),
    };
    let serialized = serde_json::to_string(&auth_req).unwrap();
    assert_eq!(
        serialized,
        "{\"method\":{\"Password\":{\"email\":\"sadf.com\",\"password\":\"password\"}}}"
    );
}

Execution Time

With llvm-cov used to invoke the nextest run command, I see execution times similar to the following:

PASS [  42.921s] app-users-types commands::tests::test_auth_req_schema_serialize

or

PASS [  14.841s] app-users-types commands::tests::test_auth_req_schema_serialize

The execution times are highly variable, depending on the load and which specific process gets prioritized at what time.

However, when I invoke cargo nextest run directly (with similar flags), the execution time falls significantly.

PASS [   1.569s] app-users-types commands::tests::test_auth_req_schema_serialize

or

PASS [   1.749s] app-users-types commands::tests::test_auth_req_schema_serialize

Environment

  • Nextest Version: 0.9.67
  • Rust Version: 1.79.0
  • OS: Alpine 3.19, Docker (docker:26.1.3-dind-alpine3.19), GitLab CI on self-managed runner (Intel(R) Core(TM) i7-9700K CPU @ 3.60GHz, 32GB DDR4 memory)

Steps to Reproduce

  1. Create a new Rust project. (This is a carrying a lot of weight -- this project contains ~70k LOC with nearly 100 dependent crates (e.g. syn, excessive use of serde, etc.) and 400+ tests which cover about half of the lines of code (in terms of line coverage).
  2. Add dependencies:
    [dependencies]
    serde = { version = "1", features = ["derive"] }
    serde_json = "1"
  3. Add the test in src/lib.rs:
    #[cfg(test)]
    mod tests {
        use serde::{Deserialize, Serialize};
    
        #[derive(Serialize, Deserialize)]
        struct UserPassAuthenticate {
            email: String,
            password: String,
        }
    
        #[derive(Serialize, Deserialize)]
        struct Authenticate {
            method: AuthenticateMethod,
        }
    
        #[derive(Serialize, Deserialize)]
        enum AuthenticateMethod {
            Password(UserPassAuthenticate),
        }
    
        #[test]
        fn test_auth_req_schema_serialize() {
            let auth_req = Authenticate {
                method: AuthenticateMethod::Password(UserPassAuthenticate {
                    email: "sadf.com".to_string(),
                    password: "password".to_string(),
                }),
            };
            let serialized = serde_json::to_string(&auth_req).unwrap();
            assert_eq!(
                serialized,
                "{\"method\":{\"Password\":{\"email\":\"sadf.com\",\"password\":\"password\"}}}"
            );
        }
    }
  4. Run the test using Nextest with llvm-cov and observe the execution time.

Additional Information

  • Command:

    cargo llvm-cov nextest \
        --locked \
        --config-file ./.config/nextest.toml \
        --features test_database_backing_impl \
        --bins --examples --tests --all-targets \
        --no-fail-fast \
        --no-report \
        --workspace
  • Config:

    [profile.default]
    slow-timeout = { period = "60s", terminate-after = 3 }
    
    [profile.default.junit]
    path = "results.xml"
    report-name = "nextest-run"
  • Other Tests:
    Execution times vary widely, with some simple tests taking up to 60 seconds.

Findings

Originally, I opened an issue here with nextest directly. However, I found that stripping llvm-cov from the command reduces test execution times to under one second for most tests, indicating that generating coverage results significantly impacts CPU, memory, and/or I/O load.

Command without llvm-cov

cargo nextest run \
      --locked \
      --config-file ./.config/nextest.toml \
      --features test_database_backing_impl \
      --bins --examples --tests --all-targets \
      --no-fail-fast \
      --workspace

Please let me know if you need further information or additional logs.

Thank you for your help!

@taiki-e
Copy link
Owner

taiki-e commented Jul 13, 2024

Thanks for the report!
Is this a problem that only occurs when combined with nextest? Or is this a problem that also occurs when using cargo-llvm-cov without nextest?

I have not seen the code, but in the latter case I wonder if it is the same problem as with #371.

Alpine 3.19, Docker

I have heard that some std APIs are very slow in musl (taiki-e/install-action#13), so maybe that is the problem...?

@taiki-e taiki-e added the C-question Category: A question label Jul 18, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
C-question Category: A question
Projects
None yet
Development

No branches or pull requests

2 participants