Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

sccache never has cache hits when invoked through cargo #193

Closed
CrendKing opened this issue Oct 21, 2017 · 7 comments
Closed

sccache never has cache hits when invoked through cargo #193

CrendKing opened this issue Oct 21, 2017 · 7 comments
Assignees

Comments

@CrendKing
Copy link

CrendKing commented Oct 21, 2017

I have Rust 1.22 nightly installed. I installed sccache with cargo install sccache (sccache 0.2.1). I followed instruction to set up RUSTC_WRAPPER=sccache. When building Rust project, no matter how many time I rebuild, sccache never has cache hits. My OS is Windows 10.

Here is an simple example. I create a snippet project with one dependency and no transitive dependency:

[dependencies]
itoa = "0.3.4"

I run cargo build -v several times and here is output:

PS C:\workspace\Rust\snippet> rm "C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib"; cargo build -v
   Compiling itoa v0.3.4
     Running `sccache rustc --crate-name itoa C:\Cargo\registry\src\github.com-1ecc6299db9ec823\itoa-0.3.4\src\lib.rs --crate-type lib --emit=dep-info,link -C debuginfo=2 -C metadata=2222172442e22589 -C extra-filename=-2222172442e22589 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --cap-lints allow`
   Compiling snippet v0.1.0 (file:///E:/Development/Rust/snippet)
     Running `sccache rustc --crate-name snippet src\main.rs --crate-type bin --emit=dep-info,link -C debuginfo=2 -C metadata=b6d470e9ce94d2a5 -C extra-filename=-b6d470e9ce94d2a5 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --extern itoa=C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib`
    Finished dev [unoptimized + debuginfo] target(s) in 1.12 secs

PS C:\workspace\Rust\snippet> rm "C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib"; cargo build -v
   Compiling itoa v0.3.4
     Running `sccache rustc --crate-name itoa C:\Cargo\registry\src\github.com-1ecc6299db9ec823\itoa-0.3.4\src\lib.rs --crate-type lib --emit=dep-info,link -C debuginfo=2 -C metadata=2222172442e22589 -C extra-filename=-2222172442e22589 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --cap-lints allow`
   Compiling snippet v0.1.0 (file:///E:/Development/Rust/snippet)
     Running `sccache rustc --crate-name snippet src\main.rs --crate-type bin --emit=dep-info,link -C debuginfo=2 -C metadata=b6d470e9ce94d2a5 -C extra-filename=-b6d470e9ce94d2a5 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --extern itoa=C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib`
    Finished dev [unoptimized + debuginfo] target(s) in 1.11 secs

PS C:\workspace\Rust\snippet> rm "C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib"; cargo build -v
   Compiling itoa v0.3.4
     Running `sccache rustc --crate-name itoa C:\Cargo\registry\src\github.com-1ecc6299db9ec823\itoa-0.3.4\src\lib.rs --crate-type lib --emit=dep-info,link -C debuginfo=2 -C metadata=2222172442e22589 -C extra-filename=-2222172442e22589 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --cap-lints allow`
   Compiling snippet v0.1.0 (file:///E:/Development/Rust/snippet)
     Running `sccache rustc --crate-name snippet src\main.rs --crate-type bin --emit=dep-info,link -C debuginfo=2 -C metadata=b6d470e9ce94d2a5 -C extra-filename=-b6d470e9ce94d2a5 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --extern itoa=C:\workspace\Rust\cargo_target\debug\deps\libitoa-2222172442e22589.rlib`
    Finished dev [unoptimized + debuginfo] target(s) in 1.10 secs

PS C:\> sccache -s
Compile requests                19
Compile requests executed        5
Cache hits                       0
Cache misses                     5
Cache timeouts                   0
Cache read errors                0
Forced recaches                  0
Cache write errors               0
Compilation failures             0
Cache errors                     0
Non-cacheable compilations       0
Non-cacheable calls             14
Non-compilation calls            0
Unsupported compiler calls       0
Average cache write          0.001 s
Average cache read miss      0.397 s
Average cache read hit       0.000 s

Notice I remove the compiled dependency before I run cargo build, and the time spent is exactly same.

Now if I directly run the first line

sccache rustc --crate-name itoa C:\Cargo\registry\src\github.com-1ecc6299db9ec823\itoa-0.3.4\src\lib.rs --crate-type lib --emit=dep-info,link -C debuginfo=2 -C metadata=2222172442e22589 -C extra-filename=-2222172442e22589 --out-dir C:\workspace\Rust\cargo_target\debug\deps -L dependency=C:\workspace\Rust\cargo_target\debug\deps --cap-lints allow

suddenly I start to get cache hits. So it looks like cargo is the culprit for the problem.

@luser
Copy link
Contributor

luser commented Oct 23, 2017

We noticed this same regression when updating to Rust 1.20 in Firefox automation, but I haven't found time to track it down yet.

@luser
Copy link
Contributor

luser commented Oct 25, 2017

Is that snippet crate you're testing with literally just an empty Rust crate with that one dependency in Cargo.toml?

@CrendKing
Copy link
Author

Yes. Empty main function. One dependency. Here is the Cargo.lock:

[root]
name = "snippet"
version = "0.1.0"
dependencies = [
 "itoa 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)",
]

[[package]]
name = "itoa"
version = "0.3.4"
source = "registry+https://github.com/rust-lang/crates.io-index"

[metadata]
"checksum itoa 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)" = "8324a32baf01e2ae060e9de58ed0bc2320c9a2833491ee36cd3b4c414de4db8c"

@luser luser self-assigned this Oct 25, 2017
@luser
Copy link
Contributor

luser commented Oct 25, 2017

I tried this locally and figured it out. Since cargo gained jobserver support, it now passes a CARGO_MAKEFLAGS env var which is different for every build. sccache uses all env vars starting with CARGO_ as inputs to the hash key for Rust compilation, so this was mucking things up. I have a patch, I'll get it landed shortly.

luser added a commit to luser/sccache that referenced this issue Oct 25, 2017
…#193

Since cargo gained jobserver support it now passes a CARGO_MAKEFLAGS
environment variable which is different for every build (it contains file
descriptor numbers or semaphore values). sccache uses all environment
variables starting with `CARGO_` as inputs to the hash key for Rust compilation
so this broke things. I think it was mostly only a problem on Windows,
where the values were semaphores. On POSIX platforms the values are file
descriptors, which are probably likely to be the same between runs of cargo.

This change also adds a test for compiling a simple Rust crate with
cargo and verifying that we get a cache hit. I pulled in the `assert_cli`
crate to write that test, which worked nicely.
luser added a commit to luser/sccache that referenced this issue Oct 25, 2017
…#193

Since cargo gained jobserver support it now passes a CARGO_MAKEFLAGS
environment variable which is different for every build (it contains file
descriptor numbers or semaphore values). sccache uses all environment
variables starting with `CARGO_` as inputs to the hash key for Rust compilation
so this broke things. I think it was mostly only a problem on Windows,
where the values were semaphores. On POSIX platforms the values are file
descriptors, which are probably likely to be the same between runs of cargo.

This change also adds a test for compiling a simple Rust crate with
cargo and verifying that we get a cache hit. I pulled in the `assert_cli`
crate to write that test, which worked nicely.
@luser luser closed this as completed in 2d9bdc1 Oct 25, 2017
@luser
Copy link
Contributor

luser commented Oct 25, 2017

Thanks for the bug report! Knowing that this bug manifested with a basically-empty crate made it much easier to diagnose than trying to build all of Firefox. :)

@CrendKing
Copy link
Author

Just to be sure, since this is easy to reproduce, could you add test to prevent regression? There could be new env variable introduce in the future that is volatile and should trigger test failure.

Also, is using all CARGO_ env variable as part of key input good design? Is it possible to identify a set of core variables and only relying on those? Basically I'm saying, instead of doing blacklisting, should we do whitelisting.

Anyway, thanks for fixing.

@luser
Copy link
Contributor

luser commented Oct 26, 2017

Just to be sure, since this is easy to reproduce, could you add test to prevent regression? There could be new env variable introduce in the future that is volatile and should trigger test failure.

Yes, I did exactly that:

/// Test that building a simple Rust crate with cargo using sccache results in a cache hit

Not having that kind of test in the first place was a pretty big oversight on my part!

Also, is using all CARGO_ env variable as part of key input good design? Is it possible to identify a set of core variables and only relying on those? Basically I'm saying, instead of doing blacklisting, should we do whitelisting.

The unfortunate thing here is that Rust code can use any environment variable via the env! macro, so this actually isn't comprehensive enough! Ideally there'd be some way for rustc to tell us what environment variables are referenced, but I chose this as a compromise that should cover most scenarios that happen in practice.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants