compile-time: massive regression during 2015

[nwin]

I noticed earlier that the compile time of image increased massively during the beginning of 2015. Unfortunately it was hard to quantify this regression since we also changed a lot during this time.

Fortunately I just found a good example that shows a 20-fold increase in compile time. It is a single file with no other dependencies (if somebody wants to try: the original version is even much older). The two revisions are exactly the same code, the newer just has been updated to compile on a recent rustc. Note that this is rustc only, no time is spend in llvm.

$ sudo rustc --version
rustc 0.13.0-nightly (7608dbad6 2014-12-31 10:06:21 -0800)
$ time sudo rustc --crate-type=lib -Z no-trans inflate.rs

real    0m1.176s
user    0m1.059s
sys 0m0.113s

(note that something is wrong with the old .pkg-file I used to install rustc, I need to use sudo to run it)

$ rustc --version
rustc 1.1.0-nightly (c4b23aec4 2015-04-29) (built 2015-04-28)
$ time rustc --crate-type=lib -Z no-trans inflate.rs

real    0m25.208s
user    0m23.919s
sys 0m1.213s

The time profiles show that driver::phase_1_parse_input and driver::phase_2_configure_and_expand almost stayed constant while the time spent in driver::phase_3_run_analysis_passes exploded.

[bluss]

If you can, bench after the merge of aecf3d8 / PR #24965 as well. Merged Fri May 1 08:33:08 2015 +0000 so it should be in the nightlies. Oh and share output of -Z time-passes too!

[nwin]

that improved marginally (edit: I checked that is after the merge)

$ rustc --version
rustc 1.1.0-nightly (c42c1e7a6 2015-05-02) (built 2015-05-01)
$ time rustc --crate-type=lib -Z no-trans inflate.rs

real    0m19.984s
user    0m18.948s
sys 0m1.033s
$ rustc --crate-type=lib -Z no-trans -Z time-passes inflate.rs
time: 0.007     parsing
time: 0.000     recursion limit
time: 0.001     configuration 1
time: 0.000     gated macro checking
time: 0.000     crate injection
time: 0.009     macro loading
time: 0.000     plugin loading
time: 0.000     plugin registration
time: 0.169     expansion
time: 0.001     complete gated feature checking 1
time: 0.018     configuration 2
time: 0.009     maybe building test harness
time: 0.008     prelude injection
time: 0.001     checking that all macro invocations are gone
time: 0.001     complete gated feature checking 2
time: 0.010     assigning node ids and indexing ast
time: 0.001     external crate/lib resolution
time: 0.002     language item collection
time: 0.037     resolution
time: 0.002     lifetime resolution
time: 0.000     looking for entry point
time: 0.000     looking for plugin registrar
time: 0.012     region resolution
time: 0.001     loop checking
time: 0.001     static item recursion checking
time: 0.002     type collecting
time: 0.001     variance inference
time: 0.129     coherence checking
time: 18.775    type checking
time: 0.048     const checking
time: 0.009     privacy checking
time: 0.000     stability index
time: 0.003     intrinsic checking
time: 0.003     effect checking
time: 0.006     match checking
time: 0.194     liveness checking
time: 0.438     borrow checking
time: 0.035     rvalue checking
time: 0.000     reachability checking
time: 0.007     death checking
time: 0.079     stability checking
time: 0.000     unused lib feature checking
time: 0.116     lint checking

[arielb1]

Your code has a >10kLOC method. Couldn't you split it?

[arielb1]

Performance does seem O(n^2) in the number of len! calls.

[nwin]

Maybe it is a duplicate of #23977?

[bluss]

Tested current nightly after the PR to inline hashing better. Only reduces run time of the type checking pass by 6%.

[pnkfelix]

Did binary search over the nightlies (thanks to multirust); problem was injected between nightly-2015-03-30 and nightly-2015-03-31

In other words, this version is fast:

rustc 1.0.0-nightly (d8be84eb4 2015-03-29) (built 2015-03-29)

and this version is slow:

rustc 1.0.0-nightly (6cf3b0b74 2015-03-30) (built 2015-03-30)

Update: scanning over git log d8be84eb4..6cf3b0b74, I wonder whether #23673 is a likely culprit.

[bluss]

@pnkfelix That's what niko is indicating with the other issue too #23977 (comment)

Edit: Awesome job bisecting though! That's a great trick to use.

[Manishearth]

I have noticed a similar effect in Servo across a particular Rust upgrade (forgot which).

Can we give this priority now that 1.0 is out?

[arielb1]

@Manishearth

Are you sure that this is the issue?

[Manishearth]

No, I'm not, but regardless, we should be fixing this with priority.

[arielb1]

The problem is that literal inference creates tons of literal variables (IntVid/FloatVid) and obligations around them, and we uselessly try to resolve these obligations.

I think of 3 ways to solve this
1) Make the operator impls built-in, essentially impl<intvar T> Add<T> for T. This would avoid creating bogus obligations.
2) dually, make check_binop not try to select_obligations_where_possible when it ends up with a float/int var. This would prevent the O(n^2)-ness, but if there are other places that select_obligations_where_possible we would have O(n m)
3) Quickly ignore obligations that didn't make progress during selection. I think this would improve selection performance, but this requires more complexity.
cc @nikomatsakis