Performance regression in nightly-2017-01-15

[jonhoo]

I've recently run into a performance regression in the Rust compiler in a project I'm working on. I've used nightlies to narrow it down to somewhere in 7789881..bf6d7b6. Specifically, the 2017-01-14 nightly is good, and 2017-01-15 is bad. The regression is independent of CARGO_INCREMENTAL=1.

If you have a machine with a few cores, you can test it on a clone of https://github.com/mit-pdos/distributary/. Run with

$ cargo run -v --release --bin vote -- --avg --articles=100000 --runtime=10 --migrate=3 soup:// | grep 'PUT+'

On -14, the "migration" mentioned in the middle finishes quite quickly. On -15, it takes a long time, and so PUT never transitions to PUT+.

I wanted to try a git bisect to narrow the problem down further, but compiling it takes forever. A cursory glance over the commit range doesn't reveal anything particularly suspect, and #rust-internals told me to post here to get some more eyes on the problem.

[frewsxcv]

Here's the commits that happened between the two commit hashes above:

7789881...bf6d7b6

[ms705]

In addition to the "migration" performance issue, note also that the benchmark's GET and PUT throughputs degraded substantially from 2017-01-14 to 2017-01-15:

2017-01-14

avg PUT: 197047.48
avg GET0: 1332991.45
avg GET: 1332991.45
avg PUT+: 153669.90
avg GET0+: 1305670.42
avg GET+: 1332991.45

2017-01-15

avg PUT: 87309.19
avg GET0: 941140.38
avg GET: 941140.38
avg PUT+: 75320.96
avg GET0+: 921691.27
avg GET+: 941140.38

[jonhoo]

So, after some more digging, it turns out that CARGO_INCREMENTAL does matter. If unset entirely, the performance regression is no longer present. CARGO_INCREMENTAL= and CARGO_INCREMENTAL=0 still experience the bug.

I'm running a git bisect now using ./x.py build --stage 1 src/libtest to re-build rust at each step, then cargo clean, and then env CARGO_INCREMENTAL=1 cargo build --bin vote --release followed by a run. Will report back once I have results.

[jonhoo]

git bisect pointed to 5f90947 as the first bad commit. I can confirm that using rustc built off of 02c7b11 with CARGO_INCREMENTAL=1 produces the expected performance, and using rustc from 5f90947 shows a significant performance decrease. If CARGO_INCREMENTAL is not set, 5f90947 performs the same as 02c7b11.

[jonhoo]

/cc #38944 @michaelwoerister

[jonhoo]

FWIW, the project in question does a significant amount of work with HashMaps, so I would hazard a guess that the performance regression is somehow related to that. I'll see if I can cook up a benchmark. Could it be that this change is somehow preventing inlining of hashing or HashMap insertions when linking with std?

[jonhoo]

And a minimal test-case showing that HashMap::insert is ~4x slower with 5f90947 and CARGO_INCREMENTAL=1.

#![feature(test)]

extern crate test;
extern crate rand;

use test::Bencher;
use rand::Rng;

#[bench]
fn hashmap_insert(b: &mut Bencher) {
    let mut val : u32 = 0;
    let mut rng = rand::thread_rng();
    let mut map = std::collections::HashMap::new();

    b.iter(|| { map.insert(rng.gen::<u8>() as usize, val); val += 1; })
}

$ diff -r bench-bad/ bench-good/
$ rustup override list | grep bench-
~/bench-good                           rust-good
~/bench-bad                            rust-bad
$ git -C ~/rust-good rev-parse HEAD
02c7b117dadcfea4416f53b4bd99828bf750871f
$ git -C ~/rust-bad rev-parse HEAD
5f90947c2c27d5d4ae30ccc0e83ffc95a8597128
$ (~/bench-good) cargo bench 
   Compiling libc v0.2.20
   Compiling rand v0.3.15
   Compiling bench-hashmap v0.1.0 (file://~/bench-good)
    Finished release [optimized] target(s) in 7.3 secs
     Running target/release/deps/bench_hashmap-0ee5f7a4b83ca3d0

running 1 test
test hashmap_insert ... bench:          39 ns/iter (+/- 3)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured

$ (~/bench-good) cargo clean; env CARGO_INCREMENTAL=1 cargo bench
   Compiling libc v0.2.20
   Compiling rand v0.3.15
   Compiling bench-hashmap v0.1.0 (file://~/bench-good)
    Finished release [optimized] target(s) in 7.39 secs
     Running target/release/deps/bench_hashmap-0ee5f7a4b83ca3d0

running 1 test
test hashmap_insert ... bench:          38 ns/iter (+/- 3)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured

$ (~/bench-bad) cargo bench
   Compiling libc v0.2.20
   Compiling rand v0.3.15
   Compiling bench-hashmap v0.1.0 (file://~/bench-bad)
    Finished release [optimized] target(s) in 7.27 secs
     Running target/release/deps/bench_hashmap-e5736083e8c2908f

running 1 test
test hashmap_insert ... bench:          38 ns/iter (+/- 3)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured

$ (~/bench-bad) cargo clean; env CARGO_INCREMENTAL=1 cargo bench
   Compiling libc v0.2.20
   Compiling rand v0.3.15
   Compiling bench-hashmap v0.1.0 (file://~/bench-bad)
    Finished release [optimized] target(s) in 7.42 secs
     Running target/release/deps/bench_hashmap-e5736083e8c2908f

running 1 test
test hashmap_insert ... bench:         133 ns/iter (+/- 13)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured

[michaelwoerister]

Thanks for the report. My guess is that the code runs slower because less inlining is happening in incremental mode. It could probably be solved by strategic placement of some #[inline] annotations in libstd.

cc @rust-lang/libs

[alexcrichton]

In general it's expected that incremental does not produce as-fast binaries as non-incremental, right? (due to a lack of inlining)

[jonhoo]

@alexcrichton it's still curious to see a regression like this though, no? also, a 4x performance decrease for HashMap::insert seems like something that might affect a lot of people, and make them want to turn of incremental compilation entirely :/