Huge compilation times after #43546

[remram44]

Previous issue: #43132 (comment)
PR: #43546

While the patch fixes the ICE for my code, it makes compilation times unacceptably slow. Furthermore, building a previous version of the code that didn't trigger the ICE got about 20 times slower.

Full reproduction steps using Docker and rustup

% docker run -ti --rm ubuntu:16.04
$ apt update && apt install curl gcc git
$ curl https://sh.rustup.rs -sSf | sh
$ . ~/.cargo/env
$ rustup toolchain install nightly-2017-07-31
$ rustup toolchain install nightly-2017-08-01
$ git clone https://gitlab.com/remram44/rs-web --single-branch --branch ICE
$ cd rs-web
$ cargo +nightly-2017-07-31 build
$ # Observe ICE
$ cargo +nightly-2017-08-01 build
$ # Observe no ICE, build time 8 minutes
$ git checkout 8fca3d957f91115349aaeb3ab58056b92d13b953
$ # Now on previous version, that always worked
$ cargo +nightly-2017-07-31 build
$ # Observe build time 6 seconds
$ cargo +nightly-2017-08-01 build
$ # Observe build time 1 minute 51 seconds

[vorner]

I think I'm hitting the same problem (I haven't actually checked this is caused by the same merge request, but I guess it would be too much coincidence). The compilation times went much higher for one of my crates (tokio-jsonrpc). This is what I get:

$ touch src/lib.rs
19:43 vorner@hydra ~/prog/tokio-jsonrpc (master 3 @1) 78%
$ CARGO_INCREMENTAL=0 cargo build --release
   Compiling tokio-jsonrpc v0.9.0 (file:///home/vorner/prog/tokio-jsonrpc)
    Finished release [optimized] target(s) in 1447.22 secs
20:07 vorner@hydra ~/prog/tokio-jsonrpc (master 3 @1) 78%

$ CARGO_INCREMENTAL=0 cargo +stable build --release
   Compiling slog v2.0.6
   Compiling byteorder v1.1.0
   Compiling scoped-tls v0.1.0
   Compiling libc v0.2.29
   Compiling unicode-xid v0.0.4
   Compiling quote v0.3.15
   Compiling num-traits v0.1.40
   Compiling futures v0.1.14
   Compiling itoa v0.3.1
   Compiling slab v0.3.0
   Compiling log v0.3.8
   Compiling cfg-if v0.1.2
   Compiling lazycell v0.5.1
   Compiling serde v1.0.11
   Compiling dtoa v0.4.1
   Compiling synom v0.11.3
   Compiling rand v0.3.16
   Compiling net2 v0.2.30
   Compiling iovec v0.1.0
   Compiling bytes v0.4.4
   Compiling syn v0.11.11
   Compiling mio v0.6.10
   Compiling tokio-io v0.1.2
   Compiling uuid v0.5.1
   Compiling tokio-core v0.1.9
   Compiling serde_json v1.0.2
   Compiling serde_derive_internals v0.15.1
   Compiling serde_derive v1.0.11
   Compiling tokio-jsonrpc v0.9.0 (file:///home/vorner/prog/tokio-jsonrpc)
    Finished release [optimized] target(s) in 95.73 secs
20:10 vorner@hydra ~/prog/tokio-jsonrpc (master 3 @1) 78%

$ rustup run stable rustc --version --verbose
rustc 1.19.0 (0ade33941 2017-07-17)
binary: rustc
commit-hash: 0ade339411587887bf01bcfa2e9ae4414c8900d4
commit-date: 2017-07-17
host: x86_64-unknown-linux-gnu
release: 1.19.0
LLVM version: 4.0
20:12 vorner@hydra ~/prog/tokio-jsonrpc (master 3 @1) 78%

$ rustc --version --verbose
rustc 1.21.0-nightly (215e0b10e 2017-08-08)
binary: rustc
commit-hash: 215e0b10eac17e43f0132971f4e2dd018fc33d43
commit-date: 2017-08-08
host: x86_64-unknown-linux-gnu
release: 1.21.0-nightly
LLVM version: 4.0
20:12 vorner@hydra ~/prog/tokio-jsonrpc (master 3 @1) 78%

The difference between 96s (including all deps) on stable and 25 minutes on nightly is huge (yes, that's release build, but anyway). My other project actually builds the release for over an hour now (https://gitlab.labs.nic.cz/turris/pakon-aggregator).

Is there anyway I can do to help with the issue?

[arielb1]

@vorner

This is very unfortunate. We might have to revert my bugfix PR + Niko's PR if we don't find a solution.

[arielb1]

OR I can try to come up with a solution. Let me see whether I can.

[arielb1]

Turns out that this problem is caused by the projection cache committing to (and caching) closure results while the evaluation cache couldn't.

This diff makes rustc fast again:

diff --git a/src/librustc/traits/select.rs b/src/librustc/traits/select.rs
index c2feb54c4d..16e075a1fc 100644
--- a/src/librustc/traits/select.rs
+++ b/src/librustc/traits/select.rs
@@ -893,7 +893,7 @@ impl<'cx, 'gcx, 'tcx> SelectionContext<'cx, 'gcx, 'tcx> {
         // being yet uninferred can create "spurious" EvaluatedToAmbig
         // and EvaluatedToOk.
         if result.is_stack_dependent() ||
-            ((result == EvaluatedToAmbig || result == EvaluatedToOk)
+            (result == EvaluatedToAmbig
              && trait_ref.has_closure_types())
         {
             return;

IIRC I added the condition because otherwise inference guessing can cause trouble (unsoundness and wrong codegen under some conditions). I think I can add Chalk-style "anti-leak" features to type inference, but I'll like to discuss it over with @nikomatsakis and @aturon.

I think I'll like to:
A) Revert #43546 and #42840 (or, more specifically, 87a1181, which I think cause #43132) for 1.20. This will un-fix the soundness bug #42796, but will avoid all new regressions and not have us race the trains.
B) For 1.21/1.22, introduce infcx leak checking detection, and enable caching for Ok results for closures when no infcx leaks were detected. Try and see how this meshes with Chalk.

[remram44]

I think I'll like to:
A) Revert #43546 and #42840

If you have a fix for the compilation time, why re-introduce #43132? Obviously I'd prefer a course of action that doesn't make rustc ICE on my code 😅

[arielb1]

@remram44

Reverting #42840 should unintroduce #43132.

[vorner]

Could I ask for what the status here is? Not that I would want to sound disrespectful or try to push anyone, only that I'm bit confused here ‒ my impression from the comments were the first thing that'd happen was to revert something, but it doesn't seem to be the case.

Or does it wait on something? On a discussion, or some code being written? Is there something I might try helping with?

[remram44]

Either way (ICE or 8min compile time) I am entirely blocked on my project, and apparently it affects other people's code, so maybe some priority (or a workaround) would be appropriate here? 1.20 is coming out soon...

[alexcrichton]

#43546 was backported so tagging this as a beta regression

[nikomatsakis]

triage: P-high

Assigning @arielb1 and myself. We've got to figure this out.

[arielb1]

The issue at gist playground - originally by @Marwes - is not fixed by the closure improvements, but rather requires a different fix.

[alexcrichton]

@arielb1 do you think this regression is "effectively fixed" with #43999 in the sense that it's not P-high as it was before?

[vorner]

I wanted to try the fix, so I compiled that branch and compared the output times. All the numbers are somewhat higher, I split the project into multiple smaller crates since the last time, which added to the total compile time (should that happen?).

• Stable: 182.57s
• Nightly: 2119.76s
• The fix: 1464.40s

So, the fix helps to some extent, but either I compiled the branch in a wrong way (but I'm pretty sure it would take much longer if I didn't enable optimisations, though), or there's still room for improvement. I have no idea what that means for the priority, though.

[vorner]

Hmm. I tried a debug build as well, for the sake of completeness. And it is odd:

• Stable: 63.47
• Nightly: 75.95
• The fix: 119.58

So I probably compiled the compiler in somewhat bad way and it is slower. I'll have to wait for the thing to get merged so I can compare it for real. Or, is it possible I observe a different problem (as it manifests a lot on release builds but not debug ones)? Is there something I can try to check if it is the same problem?

[ishitatsuyuki]

If what @vorner said is true, that PR doesn't make the issue less important. "insane time" / 2 = "insane time".

[alexcrichton]

1.20 will soon be stable

[arielb1]

This had already been fixed in 1.20

[alexcrichton]

@arielb1 oh should sthis still be open? Or tracked for 1.21 instead?

[arielb1]

Tracked for 1.21

[nikomatsakis]

So my impression is that this is fixed now on all releases. Is that correct?

[vorner]

I'm still getting somewhat strange results (is nightly compiled in a different way than stable?). The nightly is once again somewhat faster than before, but not as fast as stable.

• Today's nightly: 625
• stable 1.20: 190
• stable 1.19: 179

[nikomatsakis]

@vorner how are you reproducing those numbers? I wonder if this is affected by #44269

[nikomatsakis]

@vorner ok, I did some testing. The performance of building tokio_jsonrpc does not appear to be particularly affected by #44269 (I presume that is what you were testing).

[nikomatsakis]

I guess I will attempt some profiles and see if something jumps out.

[vorner]

Sorry for longer time for reply… and sorry for a bit of a confusion. The first numbers are from tokio_jsonrpc, the later ones are from this project (I actually haven't noticed I switched them):

https://gitlab.labs.nic.cz/turris/pakon-aggregator

I guess both are affected, maybe I have some unusual coding style (too many iterator/future combinators in a row?), or maybe it's because tokio_jsonrpc is the dependency of the other thing.

I can run some tests or profiles, if you like.

[vorner]

Did something change? It seems to be fixed for me now (on the pakon-aggregator).

• Nightly: 215 (128 with incremental compilation, which runs in multiple threads)
• stable: 218

(It's a different computer, so the stable is slightly larger than the last results, but that shouldn't matter)

[arielb1]

@vorner

Sure. @nikomatsakis landed another PR.

[vorner]

Cool. He shouldn't be that honest not to even mention it, how can I be grateful for it otherwise? :-)

[nikomatsakis]

@vorner great to here there have been improvements! I sort of expeced that, but I feel like when I tested I didn't see them, but maybe I did something wrong in my builds. :/

[nikomatsakis]

OK, as @vorner is satisfied, I'm going to close this as resolved. Feel free to re-open if you still see problems @vorner or @remram44.