Pathological case in typechecking

[alexcrichton]

This simple program takes ~1minute to compile:

macro_rules! f0( () => (1) );
macro_rules! f1( () => ({(f0!()) + (f0!())}) );
macro_rules! f2( () => ({(f1!()) + (f1!())}) );
macro_rules! f3( () => ({(f2!()) + (f2!())}) );
macro_rules! f4( () => ({(f3!()) + (f3!())}) );
macro_rules! f5( () => ({(f4!()) + (f4!())}) );
macro_rules! f6( () => ({(f5!()) + (f5!())}) );
macro_rules! f7( () => ({(f6!()) + (f6!())}) );
macro_rules! f8( () => ({(f7!()) + (f7!())}) );
macro_rules! f9( () => ({(f8!()) + (f8!())}) );
macro_rules! f10( () => ({(f9!()) + (f9!())}) );
macro_rules! f11( () => ({(f10!()) + (f10!())}) );
fn main() {
    f10!();
}

The output of -Z time-passes looks like:

time: 0.000     parsing
time: 0.000     recursion limit
time: 0.000     gated macro checking
time: 0.000     configuration 1
time: 0.000     crate injection
time: 0.012     macro loading
time: 0.000     plugin loading
time: 0.000     plugin registration
time: 0.032     expansion
time: 0.000     complete gated feature checking 1
time: 0.002     configuration 2
time: 0.001     maybe building test harness
time: 0.001     prelude injection
time: 0.000     checking that all macro invocations are gone
time: 0.000     complete gated feature checking 2
time: 0.001     assigning node ids and indexing ast
time: 0.000     external crate/lib resolution
time: 0.000     language item collection
time: 0.001     resolution
time: 0.000     lifetime resolution
time: 0.000     looking for entry point
time: 0.000     looking for plugin registrar
time: 0.001     region resolution
time: 0.000     loop checking
time: 0.000     static item recursion checking
time: 0.000     type collecting
time: 0.000     variance inference
time: 0.169     coherence checking
time: 55.344    type checking
time: 0.009     const checking
time: 0.000     privacy checking
time: 0.000     stability index
time: 0.000     intrinsic checking
time: 0.000     effect checking
time: 0.000     match checking
time: 0.000     liveness checking
time: 0.023     borrow checking
time: 0.010     rvalue checking
time: 0.000     reachability checking
time: 0.000     death checking
time: 0.000     stability checking
time: 0.000     unused lib feature checking
time: 0.004     lint checking
time: 0.000     resolving dependency formats
time: 0.002     translation
  time: 0.000   llvm function passes
  time: 0.000   llvm module passes
  time: 0.002   codegen passes
  time: 0.000   codegen passes
time: 0.007     LLVM passes
  time: 0.242   running linker
time: 0.243     linking

And profiling using OSX looks like:

cc @pnkfelix, @nikomatsakis

This was discovered in updating cargo with a rustc from 3/26 to 4/2, so it looks like it may be a recent regression?

[nikomatsakis]

This is presumably because we fixed + to use trait system. In other words, it's related to #22204 -- though not necessarily same issue exactly. We could maybe improve this specific case by examining types from LHS/RHS and hardcoding something, but I'd prefer to tackle the trait resolution performance issue (which i've been drafting some plans on...maybe time to get cracking.)

[wesleywiser]

I think this might be fixed now:

$ rustc --version
rustc 1.7.0-beta.3 (36237fc61 2016-02-11)

$ time rustc test.rs

real    0m25.614s
user    0m24.688s
sys     0m0.713s

$ rustc --version
rustc 1.8.0-nightly (c894ff6b1 2016-02-20)

$ time rustc test.rs

real    0m2.642s
user    0m2.507s
sys     0m0.119s

[jonas-schievink]

Yes, I think this was fixed by @arielb1's PR that also fixed #25916

[bluss]

This is fixed, because it's no longer pathologically slow. However, it's still slow (takes seconds to compile). With 2700 lines expanded (pretty=expanded), maybe that's ok.