rust-lang / cargo

The Rust package manager
https://doc.rust-lang.org/cargo
Apache License 2.0
12.29k stars 2.32k forks source link

cargo check shows errors when there are none and code compiles and runs cleanly otherwise #12145

Open nerdo opened 1 year ago

nerdo commented 1 year ago
          Years later, this still seems to be an issue.

I'm having a very similar problem with a similar setup. A crate with a few libs and inter-dependencies and for some reason, I kept getting an error in my ide (neovim) about a function not existing, but it does exist and the code compiles and executes cleanly otherwise.

While it's in this state, I copied the directory to another and attempted to zip it but it's too large to share (19GB! I'm assuming, because of dependencies - it's really not a huge program).

I tried running cargo clean in my main workspace, and it seemed to half fix it? I had a few errors but now it's only showing one.

It's quite annoying as I can't trust what cargo check is saying and need to fully compile much more frequently as a result.

It may be worth noting that I'm using macos, and that this project's files are sitting on an external APFS volume that I use to switch back and forth between two macos-based machines... although I'm almost certain I've come across this issue before on projects that were on an internal SSD.

Some output to demonstrate. These two commands were run back-to-back:

reaper/eat_chili/surreal_digestive on ξ‚  main [$?] is πŸ“¦ v0.1.0 via πŸ¦€ v1.69.0
❯ cargo check
    Checking surreal_digestive v0.1.0 (/Volumes/2TB/reaper/eat_chili/surreal_digestive)
error[E0599]: no method named `new_determinate` found for mutable reference `&'life2 mut ProgressProvider` in the current scope
   --> src/lib.rs:124:36
    |
124 |         let issues_step = progress.new_determinate(num_issues as u64);
    |                                    ^^^^^^^^^^^^^^^ help: there is a method with a similar name: `new_indeterminate`

For more information about this error, try `rustc --explain E0599`.
error: could not compile `surreal_digestive` due to previous error

reaper/eat_chili/surreal_digestive on ξ‚  main [$?] is πŸ“¦ v0.1.0 via πŸ¦€ v1.69.0
❯ cargo build
   Compiling futures-sink v0.3.28
   Compiling futures-channel v0.3.28
   Compiling progress_provider v0.1.0 (/Volumes/2TB/reaper/eat_chili/progress_provider)
   Compiling flume v0.10.14
   Compiling sqlx-core v0.6.3
   Compiling futures-util v0.3.28
   Compiling futures-executor v0.3.28
   Compiling tokio-tungstenite v0.18.0
   Compiling futures v0.3.28
   Compiling surrealdb v1.0.0-beta.9+20230402
   Compiling sqlx-macros v0.6.3
   Compiling sqlx v0.6.3
   Compiling chili_provider v0.1.0 (/Volumes/2TB/reaper/eat_chili/chili_provider)
   Compiling surreal_digestive v0.1.0 (/Volumes/2TB/reaper/eat_chili/surreal_digestive)
    Finished dev [unoptimized + debuginfo] target(s) in 14.16s

reaper/eat_chili/surreal_digestive on ξ‚  main [$?] is πŸ“¦ v0.1.0 via πŸ¦€ v1.69.0 took 14s
❯

Originally posted by @nerdo in https://github.com/rust-lang/cargo/issues/9971#issuecomment-1548494089

nerdo commented 1 year ago

If there are certain files I can share (or omit) from my project, please let me know and I will share. I'm keeping a copy of the current state of the project for that purpose. It's just too big to share and I don't know what files are relevant.

ehuss commented 1 year ago

I'm sorry you're having trouble with that. Can you run cargo with the CARGO_LOG=cargo::core::compiler::fingerprint=trace,cargo_util::paths=trace environment variable set, and with the --verbose CLI flag, and post the output? This will print information explaining why it doesn't recompile.

There's also information at https://doc.rust-lang.org/cargo/faq.html?highlight=faq#why-is-cargo-rebuilding-my-code for understanding why something isn't rebuilding.

nerdo commented 1 year ago

Sorry for the delay. I was traveling this past week.

I ran cargo build to confirm that it does actually build cleanly:

reaper/eat_chili_compile_issue on ξ‚  main [$!?] is πŸ“¦ v0.1.0 via πŸ¦€ v1.69.0 took 1m50s
❯ cargo build
    Finished dev [unoptimized + debuginfo] target(s) in 0.52s

reaper/eat_chili_compile_issue on ξ‚  main [$!?] is πŸ“¦ v0.1.0 via πŸ¦€ v1.69.0
❯

Then I ran this command, as requested:

❯ CARGO_LOG=cargo::core::compiler::fingerprint=trace,cargo_util::paths=trace cargo check --verbose 2>&1 | tee /tmp/cargo-output.txt

Here is the captured output.

https://gist.github.com/nerdo/e19d4e8fdf1e6fe28083cb3ca6af8bec

nerdo commented 1 year ago

I took a closer look at the output and I see several lines showing the files as dirty/stale where I expect it, namely mongo_digestive/src/lib.rs but it seems to be using cached information anyway.

[2023-05-20T16:14:52Z INFO  cargo::core::compiler::fingerprint] fingerprint dirty for mongo_digestive v0.1.0 (/Volumes/2TB/reaper/eat_chili_compile_issue/mongo_digestive)/Check { test: false }/TargetInner { ..: lib_target("mongo_digestive", ["lib"], "/Volumes/2TB/reaper/eat_chili_compile_issue/mongo_digestive/src/lib.rs", Edition2021) }
[2023-05-20T16:14:52Z INFO  cargo::core::compiler::fingerprint]     dirty: FsStatusOutdated(StaleItem(ChangedFile { reference: "/Volumes/2TB/reaper/eat_chili_compile_issue/target/debug/.fingerprint/mongo_digestive-57294996d77e6b87/dep-lib-mongo_digestive", reference_mtime: FileTime { seconds: 1684175000, nanos: 830734764 }, stale: "/Volumes/2TB/reaper/eat_chili_compile_issue/mongo_digestive/src/lib.rs", stale_mtime: FileTime { seconds: 1684178862, nanos: 537999845 } }))
ehuss commented 1 year ago

Hm, I can't tell from the output how it got into that state. My guess is that progress_provider changed (new_indeterminate renamed to new_determinate possibly?). However, it is using a stale copy of progress_provider. There is something fishy in the output. It says that:

Those are 128 hours apart. They should only ever be a few seconds apart. The .rmeta file is the output of running cargo check. The dep-lib file tracks the timestamp of when the build of that rmeta file started.

Unfortunately I don't think we'll be able to see what happened without seeing the similar debug logs from what happened on 2023-05-15 13:38:21 when the dep-info file was updated, but the rmeta file was not.

I have not seen anything quite like this. I would be suspicious of the case that this is using a removeable drive. One thing to be careful with those is to always ensure they are properly ejected so that the metadata information can get synced properly. Otherwise I don't have any other ideas.

nerdo commented 1 year ago

What you described is accurate - this manifested when I renamed/refactored new_determinate/indeterminate. I don't know why or how it happened, but it has happened to me on multiple separate occasions, even in projects on my internal ssd. I've just gotten tired of the issue and decided to see if there was an open issue on it and am reporting it.

I have a feeling something weird is happening withrust_analyzer and/or this other plugin trouble in neovim. I don't have any facts to back that up, it's just a hunch. I'm going to start removing some neovim plugins and see if the problem goes away.

Is there a way I can provide that file you mentioned when the dep-info file was updated?

ehuss commented 1 year ago

Is there a way I can provide that file you mentioned when the dep-info file was updated?

Unfortunately cargo doesn't record enough information to be able to debug this after-the-fact. The only way is to see the debug logs on the build just before and just after the problem manifests. But that requires manually recording those debug logs, which would be quite difficult and onerous.

If you can make a reproducible test cases of:

  1. Starting with everything working, run cargo check and record the full CARGO_LOG.
  2. Make a change in a dependency that would could a breaking change in the API.
  3. Run cargo check on the dependency, recording CARGO_LOG.
  4. Run cargo check on the upstream package, recording CARGO_LOG, and have this exhibit that it is not picking up the change.

I think that will be nearly impossible to do for your scenario, so I wouldn't expect you to try.

In the future we would like to have cargo record more data to be able to debug these kinds of things, but that's a long way off. Another thing we would like to experiment with is hash-based change detection (instead of mtime), but that is also a long way off.

ghashy commented 3 months ago

Hello! I am experiencing a similar issue. I am working with two crates locally on my Mac. One crate is a dependency of the other. When I update the code in the dependency crate, I need to run cargo clean in the main crate before running cargo check for it to work correctly. Without this step, when I run cargo build, it works as expected. However, when I run cargo check, it seems to be referencing an older version of the code and reports errors such as passing the wrong type:

https://github.com/rust-lang/cargo/assets/109857267/a8502e48-53fd-4b0b-97e8-ca5e82ad0c02