Possible rustc build time regression between 2017-04-14 and 2017-06-21 with CARGO_INCREMENTAL=1 and --release

[MaikKlein]

I created an repository to recreate this issue https://github.com/MaikKlein/regression/tree/59cab5ac57a668d52d33fa1e9ebca4c0b6fc9c3b

rustc --version --verbose
rustc 1.20.0-nightly (622e7e648 2017-06-21)
binary: rustc
commit-hash: 622e7e6487b6fb7fdbb901720cd4214f9179ed67
commit-date: 2017-06-21
host: x86_64-unknown-linux-gnu
release: 1.20.0-nightly
LLVM version: 4.0

CARGO_INCREMENTAL=1 cargo build --release
Finished release [optimized] target(s) in 471.63 sec

rustc --version --verbose
rustc 1.18.0-nightly (bbdaad0dc 2017-04-14)
binary: rustc
commit-hash: bbdaad0dc8dc64e036ccee817f90a91876b32a9d
commit-date: 2017-04-14
host: x86_64-unknown-linux-gnu
release: 1.18.0-nightly
LLVM version: 3.9

CARGO_INCREMENTAL=1 cargo build --release
Finished release [optimized] target(s) in 85.78 secs

I am on Ubuntu 16.04 x64.

[MaikKlein]

I added -Z time-passes output into the git repository

https://github.com/MaikKlein/regression/blob/master/output-04-14

and

https://github.com/MaikKlein/regression/blob/master/output-06-21

Here seems to be the problem

2017-06-21

  time: 5.723; rss: 499MB	llvm function passes [0]
  time: 385.102; rss: 475MB	llvm module passes [0]
  time: 22.069; rss: 462MB	codegen passes [0]
  time: 0.001; rss: 462MB	codegen passes [0]
time: 413.558; rss: 462MB	LLVM passes

[eddyb]

cc @michaelwoerister

[nagisa]

Make sure it is not fixed by #42771

[MaikKlein]

@nagisa

rustc --version --verbose
rustc 1.20.0-nightly (ab5bec255 2017-06-22)
binary: rustc
commit-hash: ab5bec25530aac43dfd64384b405c909b6e405e3
commit-date: 2017-06-22
host: x86_64-unknown-linux-gnu
release: 1.20.0-nightly
LLVM version: 4.0

This should contain #42771

CARGO_INCREMENTAL=1 cargo build --release
 Finished release [optimized] target(s) in 346.4 secs

Down from 471 seconds to 346 seconds.

[michaelwoerister]

I suspect this is because of rust-lang/cargo#4065 which makes cargo compile crates.io crates non-incrementally. The time-passes logs show many codegen units for the older toolchain and just one for the newer version.

The reasoning behind this change is that we don't need to compile things from crates.io incrementally because they don't change. That way you get a high-performance binary without impacting the ability to build your local code incrementally. When you run cargo clean though, you probably have to recompile those crates.io crates again.

@rust-lang/cargo, is there a way to keep crates.io dependencies around when doing a cargo clean?

[michaelwoerister]

I opened rust-lang/cargo#4234 in relation to this.

[michaelwoerister]

rust-lang/cargo#4234 has been merged. Care to give it another try with the latest Cargo, @MaikKlein?

[MaikKlein]

@michaelwoerister It is much better now.

Finished release [optimized] target(s) in 147.29 secs

Although I am not sure about the multi threading. I know gnome-system-monitor is not the most reliable tool but this is what the compilation looks. https://i.imgur.com/qyHaC5f.png

rustc --version --verbose
rustc 1.20.0-nightly (2fbba5bdb 2017-07-04)
binary: rustc
commit-hash: 2fbba5bdbadeef403a64e9e1568cdad225cbcec1
commit-date: 2017-07-04
host: x86_64-unknown-linux-gnu
release: 1.20.0-nightly
LLVM version: 4.0

cargo --version --verbose
cargo 0.21.0-nightly (eb6cf012a 2017-07-02)
release: 0.21.0
commit-hash: eb6cf012a6cc23c9c89c4009564de9fccc38b9cb
commit-date: 2017-07-02

[michaelwoerister]

Although I am not sure about the multi threading.

Does the graph stay that way? Only the LLVM part is multi-threaded, so the other cores can only be used towards the end of compilation. On the other hand, if this is a build with full re-use, then the LLVM part is skipped entirely and you won't see any multi-threading.

[MaikKlein]

@michaelwoerister I am doing cargo clean before I build.

I watched it now a couple of times and it only uses multiple cores in the beginning. After around 60s only one core is at 100% for the rest of the compilation. (see the image above)

Are there any good tools to record data for cpu usage? I looked at top but that isn't really readable.