Reasons for rebuilding

[dnbln]

What does this PR try to resolve?

Attempts to provide some reasons for why crates are rebuilt (issue #2904 has been around for a very long time).

Basically adds an Option<DirtyReason> to Job, returned by the Fingerprint::compare method, and displays it in DrainState::note_working_on, almost analogous to displaying Fresh, but unlike Fresh, it is displayed regardless of verbosity, though with -v it gives a few more details Edit: now only displayed with --verbose. Also needed to add a few FsStatus variants to track why it was stale, to be able to display that information.

How should we test and review this PR?

I updated the freshness tests with the correct outputs after the change. Unsure if any of the other tests need to be changed. Edit: turns out quite a few did.

Additional information

Topic on zulip.

As for the actual presentation, it definitely can be improved, and I would love to hear some other thoughts on it. There are some variants that seem pretty enigmatic, and that I have few ideas how to actually present in any meaningful way (specifically: CompileKindChanged, LocalLengthsChanged, PrecalculatedComponentsChanged, DepInfoOutputChanged, LocalFingerprintTypeChanged, and NothingObvious).

Fixes #2904

[rustbot]

Thanks for the pull request, and welcome! The Rust team is excited to review your changes, and you should hear from @epage (or someone else) soon.

Please see the contribution instructions for more information.

[epage]

r? @weihanglo

As I'm unlikely to catch up on this topic and get to this at this time

[dnbln]

Those failing tests... they pass on my machine (on windows, with the nightly msvc toolchain), but for some reason something else happens on linux and the changes in the fingerprint aren't detected anymore(dirty_reason = None, leading to nothing being displayed and the crate just gets recompiled, with no explanation why, so the tests fail).

I saw this comment:

cargo/tests/testsuite/freshness.rs

Lines 496 to 501 in ab18bd4

	// MSVC does not include hash in binary filename, so it gets recompiled.
	if cfg!(target_env = "msvc") {
	e.with_stderr("[COMPILING] foo[..]\n[FINISHED] dev[..]");
	} else {
	e.with_stderr("[FINISHED] dev[..]");
	}

So I'm going to do the same thing for the remaining failing tests, and hope a rollback would be easy if necessary.

[bors]

☔ The latest upstream changes (presumably #11417) made this pull request unmergeable. Please resolve the merge conflicts.

[weihanglo]

Fabulous! I really love how Dirty message gets encoded. It is almost good to go!

For From and To message, it may be a debate on them. If possible, could we spin off them to a follow-up pull request?

[weihanglo]

Is it possible to avoid this kind of clone? For this specific rustflags changed, it would be cloned over for all dependencies in your dependencies graph of your crate.

[dnbln]

I'm not sure I understand your concern, but maybe using InternedString instead could help? Or alternatively move the

        if !self.fs_status.up_to_date() {
            bail!(DirtyReason::FsStatusOutdated(FsStatusOutdated::new(
                self.fs_status.clone()
            )))
        }

Check before the others, which would force most of the crates to have the reason of "dependency ... was rebuilt" instead of one of the more potentially specific ones. It corresponds to this variant:

cargo/src/cargo/core/compiler/fingerprint.rs

Lines 587 to 591 in e08848c

	StaleDependency {
	name: InternedString,
	dep_mtime: Option<FileTime>,
	max_mtime: FileTime,
	},

Which is also a lot cheaper to clone.

[weihanglo]

I meant avoid some clones like these inside DirtyReason. A little overhead is present even during non-verbose mode. Though to fix it, we might introduce quirky lifetime annotations 😞.

Not really a blocker to me if others feel fine with it.

diff --git a/src/cargo/core/compiler/fingerprint.rs b/src/cargo/core/compiler/fingerprint.rs
index 474ce169f..1e2545878 100644
--- a/src/cargo/core/compiler/fingerprint.rs
+++ b/src/cargo/core/compiler/fingerprint.rs
@@ -855,8 +855,8 @@ impl Fingerprint {
         }
         if self.features != old.features {
             bail!(DirtyReason::FeaturesChanged {
-                old: old.features.clone(),
-                new: self.features.clone()
+                old: &old.features,
+                new: &self.features,
             });
         }
         if self.target != old.target {
@@ -870,8 +870,8 @@ impl Fingerprint {
         }
         if self.rustflags != old.rustflags {
             bail!(DirtyReason::RustflagsChanged {
-                old: old.rustflags.clone(),
-                new: self.rustflags.clone(),
+                old: &old.rustflags,
+                new: &self.rustflags,
             })
         }
         if self.metadata != old.metadata {
diff --git a/src/cargo/core/compiler/fingerprint/dirty_reason.rs b/src/cargo/core/compiler/fingerprint/dirty_reason.rs
index 025aa8ee1..6f0d9f552 100644
--- a/src/cargo/core/compiler/fingerprint/dirty_reason.rs
+++ b/src/cargo/core/compiler/fingerprint/dirty_reason.rs
@@ -5,47 +5,47 @@ use crate::Config;
 use std::fmt;
 
 #[derive(Debug)]
-pub enum DirtyReason {
+pub enum DirtyReason<'a> {
     RustcChanged,
     FeaturesChanged {
-        old: String,
-        new: String,
+        old: &'a str,
+        new: &'a str,
     },
     TargetConfigurationChanged,
     PathToSourceChanged,
     ProfileConfigurationChanged,
     RustflagsChanged {
-        old: Vec<String>,
-        new: Vec<String>,
+        old: &'a [String],
+        new: &'a [String],
     },

[dnbln]

That would mean the lifetime would be added to Job, and store both the new and the old Arc<Fingerprint>s somewhere (e.g. in Job, so we run into the issue of lifetime-of-other-field). Alternatively, we could make the Fingerprint::compare method take in owned values and return them, skipping the need to clone, but then the write_fingerprint call wouldn't have a Fingerprint to work with. In the case of the first one, I guess it'd be possible and feasible to remove all the expensive-to-clone fields from DirtyReason, and to make the old and the new Fingerprint fields of DirtyReasonPresentation, to get them from there instead, but then the fingerprints themselves would live for a lot more than they probably should(edit: nevermind, that happens anyway because of write_fingerprint), and also the logs that use <DirtyReason as Display> would lose all those details.

[weihanglo]

From the other angle, the message is quite useful, but only in verbose mode. I wonder if we can avoid the tiny overhead when not in verbose mode.

[dnbln]

It would be possible, maybe with another enum DirtyReasonRef<'a> and using the references from the Fingerprints, coupled with some mechanism to turn a DirtyReasonRef<'a> to DirtyReason (maybe similar to ToOwned) by cloning the references, invoked only in verbose mode, but that would involve changing the Result of the Fingerprint::compare function to something like Result<(), DirtyReasonRef<'a>>, since anyhow::Errors have to be 'static. I'm not really sure if that is really worth it, but I might be wrong.

[weihanglo]

You're totally right. It might not be that worthy, depending on how much code to change, as freshness check is not really in the hot path.

[ehuss]

Just a quick comment on the overall approach, I think this should only be displayed with --verbose, similar to the "Fresh" status message. Cargo is already pretty verbose in the default mode, and we may be looking to remove some of the output it already has. Adding more output is kinda going in the opposite direction.

I haven't had a chance to look at this more closely, but I think it will be great to have!

[weihanglo]

Thank you for the update!

What I meant in the previous review is maybe we could remove From/To status and all relevant machinery (StaleItem, StaleDependency and so on). So that we can focus moving old logging into verbose output. Then we extend it to the innovative From/To format in the next PR. It would make PR easier to reach a consensus.

That's just my personal idea, though. Other people may have different thoughts.

BTW, cargo build --verbose prints all rustc invocations already. Does anyone feel it is so verbose that users might mess freshness status?

[dnbln]

Thank you for the update!

What I meant in the previous review is maybe we could remove From/To status and all relevant machinery (StaleItem, StaleDependency and so on). So that we can focus moving old logging into verbose output.

StaleItem and StaleDependency were not actually used for From/To, but for the regular Dirty, here:

cargo/src/cargo/core/compiler/fingerprint/dirty_reason.rs

Lines 451 to 496 in 00b81c2

	FsStatus::StaleItem { item } => match item {
	StaleItem::MissingFile(missing_file) => {
	let file = missing_file.strip_prefix(root).unwrap_or(&missing_file);
	s.dirty_because(unit, format!("the file `{}` is missing", file.display()))
	}
	StaleItem::ChangedFile {
	stale,
	stale_mtime,
	reference_mtime,
	..
	} => {
	let file = stale.strip_prefix(root).unwrap_or(&stale);
	s.dirty_because(
	unit,
	format!(
	"the file `{}` has changed ({})",
	file.display(),
	Self::after(*reference_mtime, *stale_mtime, "last build"),
	),
	)
	}
	StaleItem::ChangedEnv { var, .. } => {
	s.dirty_because(unit, format!("the environment variable {var} changed"))?;
	Ok(())
	}
	},
	FsStatus::StaleDependency {
	name,
	dep_mtime,
	max_mtime,
	..
	} => {
	let message = match dep_mtime {
	Some(dep_mtime) => {
	format!(
	"the dependency {name} was rebuilt ({})",
	Self::after(*max_mtime, *dep_mtime, "last build"),
	)
	}
	None => {
	format!("the dependency {name} was rebuilt")
	}
	};
	s.dirty_because(unit, message)
	}

Changing files and rebuilding dependencies are perhaps the most common reasons why cargo would decide to rebuild a crate, so I think more concrete information would be very useful (rather than just "this is stale", which would be the case if we removed them).

Then we extend it to the innovative From/To format in the next PR. It would make PR easier to reach a consensus.

That's just my personal idea, though. Other people may have different thoughts.

Regarding From/To, adding them back in should be as easy as reverting e08848c, which is why I did it in a single commit.

BTW, cargo build --verbose prints all rustc invocations already. Does anyone feel it is so verbose that users might mess freshness status?

Yes, that is indeed the case, so maybe a special log option specifically for this would be the way to go (maybe enabled by default with --verbose too?).

[weihanglo]

Ok now I see it. I'll try to bring this up to the next few Cargo meetings then we can move on. Thank you for the work so far!

[weihanglo]

Hi @dnbln. The Cargo team talked about this in the triage meeting today. We appreciate your efforts so far and are happy to move forward!

Like I guessed, we had some concerns around how to display it based on this screenshot. For example, From and To might be better as a part of Dirty status, instead of putting them in their own status. We also discussed default to writing fingerprint info to a logfile, as it's often too late to realize you need to enable verbose/logging mode to check rebuild fingerprints. The discussion was also expanded to moving to a more structural logging implementation, such as tracing.

Anyhow, the team agreed that this PR is in a good state to merge, given it only prints Dirty status when in verbose mode, which is way more discoverable than CARGO_LOG. We can continue exploring other possibilities as future extensions afterwards.

If you are ready, please flag this as ready-to-review, and perhaps attach some more screenshots to help other reviewers catch up which UI has been changed. Thank you!

[dnbln]

Hello!

We appreciate your efforts so far and are happy to move forward!

I'm happy to hear that!

For example, From and To might be better as a part of Dirty status, instead of putting them in their own status.

The initial line of reasoning to put them on separate lines was that if they are right under one another, the difference can be spotted easily, at least much easier than if they were on the same line. Some of them can be really long too (for example environment variables containing paths, and may not really fit on the same line). I've already removed them in e08848c, but let me know if I should add them back in (even as parts of the Dirty status).

We also discussed default to writing fingerprint info to a logfile, as it's often too late to realize you need to enable verbose/logging mode to check rebuild fingerprints.

Maybe it is. Initially what drove me to write this patch was to figure out why 2 crates kept recompiling again and again (causing the rebuild of ~60 others) at every invocation of cargo (typenum and winapi specifically, turned out to be because of something to do with their build script when compiled with MSVC, I am not sure what exactly). I find it somewhat tolerable when it just happens once, but when that is triggered at every cargo build and cargo test the --verbose flag can help pinpoint the issue, so in practice (most of the time at least) I don't think it would be too late since running cargo in verbose mode with a crate that always rebuilds would still tell you why (since debugging specifically that would most likely be why you would be using this in the first place).

Anyhow, the team agreed that this PR is in a good state to merge, given it only prints Dirty status when in verbose mode, which is way more discoverable than CARGO_LOG.

That is already the case after 1966436.

If you are ready, please flag this as ready-to-review, and perhaps attach some more screenshots to help other reviewers catch up which UI has been changed. Thank you!

Here are some more screenshots (of what it looks like right now, after 95064a0):

For file changes:

Rebuilding dependency because of a file change in that dependency:

Feature set changes:

env!-macro referenced environment variables:

or build.rs cargo:rerun-if-env-changed:

build.rs cargo:rerun-if-changed:

Most of the others are hardly if ever at all displayed (since different fingerprint hashes are always going to trigger a new build with Job::new_dirty(..., None))

For more, feel free to take a look over the patched tests (not too many actually use -v, so I should probably write some more😅).

[dnbln]

I'm not entirely sure I got these bits right, so I'll ask here.

[weihanglo]

Thank you for the update. I didn't realize putting too many comments until now 😆

There are things could be improved:

• DirtyReasonDeps is not used anymore. Should remove it and relevant usages.
• It is better to commit formatting changes in a separate commit or even a separate PR.
• Some new types and functions seem not necessary. Maybe I missed something and you can explain them.
• I'd like to see tests exercising those new Dirty status. Perhaps turn on --verbose for some tests under tests/testsuite/freshness? For example, some newly added message in DirtyReason::FsStatusOutdated worth a test.

[dnbln]

Thank you for the review!

I applied a few suggestions in the last few commits.

I will work more on this over the weekend; probably also rebase at some point to fix those changes that shouldn't have been there.

Since there's more work to be done, I'm marking this as a draft for now.

[dnbln]

Seems like the tests pass again. I've squashed all the commits into 0beb5fe (including the fixes for most of the comments above), and 2071acd adds --verbose to a few features tests (just so [DIRTY-MSVC] gets used somewhere 😅). Marking this as ready for review again.

[dnbln]

Another question: what to do about changes to directories? Using the file `...` ... seems misleading.

[weihanglo]

Thank you for the update! It's almost ready to merge :)

[weihanglo]

Looks good to me. Some dirty messages are not exercised but can be added afterward.

Let's move on. Thank you!

[weihanglo]

@bors r+

[bors]

📌 Commit 6913486 has been approved by weihanglo

It is now in the queue for this repository.

[bors]

⌛ Testing commit 6913486 with merge dd99005...

[bors]

☀️ Test successful - checks-actions
Approved by: weihanglo
Pushing dd99005 to master...