<p dir="auto">I noticed earlier that the compile time of <code class="notranslate">image</code> increased massively during the beginning of 2015. Unfortunately it was hard to quantify this regression since we also changed a lot during this time.</p>
<p dir="auto">Fortunately I just found a good example that shows a 20-fold increase in compile time. It is a <a href="https://gist.github.com/nwin/b0b8bb23040a526b5b59">single file</a> with no other dependencies (if somebody wants to try: the <a href="https://github.com/cmr/TEMP-rust-png">original version</a> 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 <code class="notranslate">rustc</code> only, no time is spend in llvm.</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="$ 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"><pre class="notranslate"><code class="notranslate">$ 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
</code></pre></div>
<p dir="auto">(note that something is wrong with the old .pkg-file I used to install rustc, I need to use sudo to run it)</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="$ 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"><pre class="notranslate"><code class="notranslate">$ 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
</code></pre></div>
<p dir="auto">The <a href="https://gist.github.com/nwin/016c7e64ae270f519cdb">time profiles</a> show that <code class="notranslate">driver::phase_1_parse_input</code> and <code class="notranslate">driver::phase_2_configure_and_expand</code> almost stayed constant while the time spent in <code class="notranslate">driver::phase_3_run_analysis_passes</code> exploded.</p>
<p dir="auto">This simple program takes ~1minute to compile:</p>
<div class="highlight highlight-source-rust notranslate position-relative overflow-auto" dir="auto" data-snippet-clipboard-copy-content="macro_rules! f0( () =&gt; (1) );
macro_rules! f1( () =&gt; ({(f0!()) + (f0!())}) );
macro_rules! f2( () =&gt; ({(f1!()) + (f1!())}) );
macro_rules! f3( () =&gt; ({(f2!()) + (f2!())}) );
macro_rules! f4( () =&gt; ({(f3!()) + (f3!())}) );
macro_rules! f5( () =&gt; ({(f4!()) + (f4!())}) );
macro_rules! f6( () =&gt; ({(f5!()) + (f5!())}) );
macro_rules! f7( () =&gt; ({(f6!()) + (f6!())}) );
macro_rules! f8( () =&gt; ({(f7!()) + (f7!())}) );
macro_rules! f9( () =&gt; ({(f8!()) + (f8!())}) );
macro_rules! f10( () =&gt; ({(f9!()) + (f9!())}) );
macro_rules! f11( () =&gt; ({(f10!()) + (f10!())}) );
fn main() {
    f10!();
}"><pre class="notranslate"><span class="pl-k">macro_rules!</span> f0<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-c1">1</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f1<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f0!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f0!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f2<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f1!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f1!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f3<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f2!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f2!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f4<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f3!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f3!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f5<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f4!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f4!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f6<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f5!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f5!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f7<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f6!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f6!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f8<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f7!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f7!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f9<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f8!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f8!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f10<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f9!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f9!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">macro_rules!</span> f11<span class="pl-kos">(</span> <span class="pl-kos">(</span><span class="pl-kos">)</span> =&gt; <span class="pl-kos">(</span><span class="pl-kos">{</span><span class="pl-kos">(</span>f10!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span> + <span class="pl-kos">(</span>f10!<span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">)</span><span class="pl-kos">}</span><span class="pl-kos">)</span> <span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-k">fn</span> <span class="pl-en">main</span><span class="pl-kos">(</span><span class="pl-kos">)</span> <span class="pl-kos">{</span>
    <span class="pl-en">f10</span><span class="pl-en">!</span><span class="pl-kos">(</span><span class="pl-kos">)</span><span class="pl-kos">;</span>
<span class="pl-kos">}</span></pre></div>
<p dir="auto">The output of <code class="notranslate">-Z time-passes</code> looks like:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="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"><pre class="notranslate"><code class="notranslate">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
</code></pre></div>
<p dir="auto">And profiling using OSX looks like:</p>
<p dir="auto"><a target="_blank" rel="noopener noreferrer nofollow" href="https://camo.githubusercontent.com/5afa31442840be451122263d133608bdf6459b62f30057859b98a9b0eb38ccae/68747470733a2f2f692e696d6775722e636f6d2f704a37396e30322e6a7067"><img src="https://camo.githubusercontent.com/5afa31442840be451122263d133608bdf6459b62f30057859b98a9b0eb38ccae/68747470733a2f2f692e696d6775722e636f6d2f704a37396e30322e6a7067" alt="https://i.imgur.com/pJ79n02.jpg" data-canonical-src="https://i.imgur.com/pJ79n02.jpg" style="max-width: 100%;"></a></p>
<p dir="auto">cc <a class="user-mention notranslate" data-hovercard-type="user" data-hovercard-url="/users/pnkfelix/hovercard" data-octo-click="hovercard-link-click" data-octo-dimensions="link_type:self" href="https://github.com/pnkfelix">@pnkfelix</a>, <a class="user-mention notranslate" data-hovercard-type="user" data-hovercard-url="/users/nikomatsakis/hovercard" data-octo-click="hovercard-link-click" data-octo-dimensions="link_type:self" href="https://github.com/nikomatsakis">@nikomatsakis</a></p>
<p dir="auto">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?</p>