taiki-e / cargo-llvm-cov

Cargo subcommand to easily use LLVM source-based code coverage (-C instrument-coverage).
Apache License 2.0
953 stars 58 forks source link

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

Open seanpianka opened 4 months ago

seanpianka commented 4 months ago

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

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

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 commented 4 months ago

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 https://github.com/taiki-e/cargo-llvm-cov/issues/371.

Alpine 3.19, Docker

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