Cargo should not use rustc cache results (.rustc_info.json) for failures

[tomoverlund]

Problem

So I was setting up a customized rustc, stepping outside the bounds of rustup toolchains, and I got an error invoking rustc when running Cargo. I fix the error, then re-run, and immediately get the same error. I run strace to see if I can spot the problem, and I see the error message printed, but no system call to run rustc. I was going crazy!

I finally traced this to src/cargo/util/rustc.rs::cached_output():

if self.data.outputs.contains_key(&key) {
    debug!("rustc info cache hit");
} else {
    // run command
}
let output: &Output = &self.data.outputs[&key];
if output.success {
    Ok((output.stdout.clone(), output.stderr.clone()))
} else {
    Err(ProcessError::new_raw(
        msg: &format!("process didn't exit successfully: {}", cmd),
        output.code,
        &output.status,
        stdout: Some(output.stdout.as_ref()),
        stderr: Some(output.stderr.as_ref()),
    ) ProcessError                                                                                                                                                 
    .into())
}

After I removed the .rustc_info.json cache file, my cargo invocation worked. So long story short, considering that command caches are imperfect, it should not cache failures, to give the user the best chance of fixing the problem.

I also think if a cached result is used, it should append a (cached) to the standard output, because the cache is imperfect, and this might be a vital clue if something is not being rebuilt when the user expects it to be.

Steps

No response

Possible Solution(s)

No response

Notes

No response

Version

[epage]

While root cause is different, the caching of failures was previously discussed in #14385.

It sounds like in this case, the concern is in specifically dealing with errors in developing a custom rustc / rustc wrapper and not regular development operations. While frustrating, I have a feeling that use case is small enough / rare enough that it wouldn't outweigh the benefits of the caching for all other use cases. The idea of reporting the caching to stdout was also mentioned but that could end up being quite noisy for a detail that doesn't matter to most people when we already want to be shrinking the amount of output we generate.

[tomoverlund]

Thanks for the link. First, I would note that rustc wrappers are explicitly supported by Cargo. Second, I would note that you now have multiple bug reports from different forms of cache-on-failure causing problems.

Now to respond from some linked comments:

In #14385, there's:

Caching of failures was intentionally added in #9112 (cc5e9df)

And in #9112, there's (from @alexcrichton ):

while also preserving a pleasant debugging experience by default

Debugging mystery errors that defy logic is not pleasant. You already ran into an issue, did the obvious thing to fix it, and there's no indication as to why it isn't working.

Also:

The main thing I did was to update the rustc caching to cache failure statuses as well as successful statuses when we learn about rustc args so we can cache the failure to use -Csplit-debuginfo on platforms it's not stable or on.

This I don't understand. Can this be further explained?

Finally, on outputting (cached):

that could end up being quite noisy for a detail that doesn't matter to most people when we already want to be shrinking the amount of output we generate

It would be a minor thing to append that I think would at least be appropriate for verbose, where the commands being run are given. I'd be willing to cook up a patch and show the output as a proposal.

[tomoverlund]

Oh, I missed this

This commit updates the rustc info cache to cache failures to execute
rustc as well as successes. This fixes a weird issue where if you're
probing for flags the rustc_info_cache test fails on channels which
don't have the flag since previously a failure to execute rustc resulted
in never caching the result.

So it's purely from internal tests. As a priority, I would think drive-you-crazy bugs by users are more important than a hammer to squash a fly in the ointment of Rust's internal testing. Could this not be made an explicit option, to use in that case?

[tomoverlund]

Sorry if I seem like I'm talking to myself or piling on, but I'm still digging and note this is your take from #14385:

epage on Aug 19, 2024

While miri and clippy can workaround this, it is a foot gun for anyone writing a RUSTC_WRAPPER and I'd prefer that we not have tests be negatively impacting the user experience like that.

I agree with that guy. Whatever happened to him? How did it become "While frustrating, I have a feeling that use case is small enough / rare enough that it wouldn't outweigh the benefits of the caching for all other use cases.", and "all other use cases" is internal testing?

I will keep digging and see if I can modify the tests so that they behave properly without exposing users to cache-on-failure.

[tomoverlund]

I have proposed a fix. What I did was keep the caching of failures, but if a failure is found, the cache result will not be used. Instead, the command is run again:

if self.data.outputs.contains_key(&key) && self.data.outputs[&key].success {
    // use cache results
} else {
    // run command again
}

To deal with the testsuite/rustc_info_cache.rs issue, I added distinct debug messages for cache behavior based on whether the command was successful or not. So, for example, when rustc_info_cache.rs checks that there is no update of the cache on a cargo rebuild:

// const UPDATE_NEWCACHE: &str = "[..]updated rustc info cache (NewCache)[..]";
.with_stderr_does_not_contain(UPDATE_NEWCACHE)

it will not find an update that occurred because a command failed:

//const UPDATE_FAILURE: &str = "[..]updated rustc info cache (HitFailure)[..]";

I tested with cargo test against stable and nightly and all was well. I also tested this against a modified src/cargo/core/compiler/build_context/target_info.rs to simulate a probe failure, reproducing the original situation in #9112:

// Note bogus "xsplit"
let x_supports_split_debuginfo = rustc
    .cached_output(process.clone().arg("-Cxsplit-debuginfo=packed"), extra_fingerprint)
    .is_ok();
debug!("x_supports_split_debuginfo: {}", x_supports_split_debuginfo);

and I verified rustc_info_cache.rs failed without my fix, and passed with it.