Test coverage being missed with assert_cmd package

[MilesCranmer]

Hey,

Awesome package, I really appreciate your work maintaining this!

I'm trying to debug why tarpaulin isn't picking up my binary tests for my rust project rip2: https://github.com/MilesCranmer/rip2. I have started using assert_cmd to test the CLI functionality but it doesn't seem to get picked up by tarpaulin at all.

I have been running tarpaulin with the following options:

cargo tarpaulin --engine llvm --follow-exec --out=Lcov -- test_cli

I have an integration test here that uses assert_cmd to call the rip binary with different options.

However, these don't seem to be picked up. I've read through the solutions on #903 but they didn't seem to help me. Here is the current output:

Finished test [unoptimized + debuginfo] target(s) in 13.21s
2024-04-11T03:44:32.262681Z  INFO cargo_tarpaulin::process_handling: running /Users/mcranmer/PermaDocuments/rip/target/debug/deps/rip-9723570d6298e012
2024-04-11T03:44:32.262727Z  INFO cargo_tarpaulin::process_handling: Setting LLVM_PROFILE_FILE

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

2024-04-11T03:44:32.438859Z  INFO cargo_tarpaulin::statemachine::instrumented: For binary: target/debug/deps/rip-9723570d6298e012
2024-04-11T03:44:32.438870Z  INFO cargo_tarpaulin::statemachine::instrumented: Generated: target/tarpaulin/profraws/rip-9723570d6298e012_14156139374758574137_0-62036.profraw
2024-04-11T03:44:32.438873Z  INFO cargo_tarpaulin::statemachine::instrumented: Merging coverage reports
2024-04-11T03:44:32.447034Z  INFO cargo_tarpaulin::statemachine::instrumented: Mapping coverage data to source
2024-04-11T03:44:32.565754Z  INFO cargo_tarpaulin::process_handling: running /Users/mcranmer/PermaDocuments/rip/target/debug/deps/unit_tests-58106ca4ac690a6c
2024-04-11T03:44:32.565804Z  INFO cargo_tarpaulin::process_handling: Setting LLVM_PROFILE_FILE

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 15 filtered out; finished in 0.00s

2024-04-11T03:44:32.866785Z  INFO cargo_tarpaulin::statemachine::instrumented: For binary: target/debug/deps/unit_tests-58106ca4ac690a6c
2024-04-11T03:44:32.866797Z  INFO cargo_tarpaulin::statemachine::instrumented: Generated: target/tarpaulin/profraws/unit_tests-58106ca4ac690a6c_11063364119811431340_0-62037.profraw
2024-04-11T03:44:32.866799Z  INFO cargo_tarpaulin::statemachine::instrumented: Merging coverage reports
2024-04-11T03:44:32.882143Z  INFO cargo_tarpaulin::statemachine::instrumented: Mapping coverage data to source
2024-04-11T03:44:33.134842Z  INFO cargo_tarpaulin::process_handling: running /Users/mcranmer/PermaDocuments/rip/target/debug/deps/rip2-5a19ef321941f7f6
2024-04-11T03:44:33.134918Z  INFO cargo_tarpaulin::process_handling: Setting LLVM_PROFILE_FILE

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

2024-04-11T03:44:33.392793Z  INFO cargo_tarpaulin::statemachine::instrumented: For binary: target/debug/deps/rip2-5a19ef321941f7f6
2024-04-11T03:44:33.392804Z  INFO cargo_tarpaulin::statemachine::instrumented: Generated: target/tarpaulin/profraws/rip2-5a19ef321941f7f6_12520403362171216094_0-62038.profraw
2024-04-11T03:44:33.392806Z  INFO cargo_tarpaulin::statemachine::instrumented: Merging coverage reports
2024-04-11T03:44:33.403659Z  INFO cargo_tarpaulin::statemachine::instrumented: Mapping coverage data to source
2024-04-11T03:44:33.517893Z  INFO cargo_tarpaulin::process_handling: running /Users/mcranmer/PermaDocuments/rip/target/debug/deps/integration_tests-7b491feadfa88650
2024-04-11T03:44:33.517943Z  INFO cargo_tarpaulin::process_handling: Setting LLVM_PROFILE_FILE

running 7 tests
test test_cli::scenario_1___help__ ... ok
test test_cli::scenario_2___help2__ ... ok
test test_cli::scenario_3___bury_unbury__ ... ok
test test_cli::scenario_4___bury_seance__ ... ok
test test_cli::scenario_5___bury_unbury_seance__ ... ok
test test_cli::scenario_6___inspect__ ... ok
test test_cli::scenario_7___inspect_no__ ... ok

test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 11 filtered out; finished in 0.43s

2024-04-11T03:44:34.193509Z  INFO cargo_tarpaulin::statemachine::instrumented: For binary: target/debug/deps/integration_tests-7b491feadfa88650
2024-04-11T03:44:34.193520Z  INFO cargo_tarpaulin::statemachine::instrumented: Generated: target/tarpaulin/profraws/integration_tests-7b491feadfa88650_17302080270570845666_0-62039.profraw
2024-04-11T03:44:34.193524Z  INFO cargo_tarpaulin::statemachine::instrumented: Merging coverage reports
2024-04-11T03:44:34.211205Z  INFO cargo_tarpaulin::statemachine::instrumented: Mapping coverage data to source
2024-04-11T03:44:34.460016Z  INFO cargo_tarpaulin::report: Coverage Results:
|| Tested/Total Lines:
|| src/args.rs: 0/24 +0.00%
|| src/lib.rs: 0/263 +0.00%
|| src/main.rs: 0/16 +0.00%
|| src/util.rs: 0/38 +0.00%
|| 
0.00% coverage, 0/341 lines covered, +0.00% change in coverage

^ Oddly you can see that despite all the test_cli tests being run, where this line is used to get the binary for the package, the coverage doesn't get picked up. The main tests that should trigger this behavior are test_cli::* in the integration tests.

(If I turn on the other tests which directly call the library functions, the coverage does work. It's just the binary/CLI components I'm struggling with).

The solutions on #903 didn't seem to help me sadly. If there are any other CLI flags I can try, please let me know.

Can reproduce this with:

git clone https://github.com/MilesCranmer/rip2
cd rip2
cargo tarpaulin --engine llvm --follow-exec --out=Lcov -- test_cli

^ Which will show the 0%.

Cheers,
Miles

[xd009642]

Hmm I'll have to look into it once the nightly issues are resolved, one thought though is that follow-exec doesn't work necessarily properly on llvm coverage depending on your tests the profraw files may be written after your test asserts the command works properly (depending on the method of the assert). So the arg --post-test-delay was designed to make it work by adding a fudge factor delay after the main test process exits to collect all the profraws

[MilesCranmer]

Thanks, I tried --post-test-delay=10 but still at 0% unfortunately.