Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Nonlinear compile time blow-up with deeply nested types #38528

Closed
sfackler opened this Issue Dec 22, 2016 · 40 comments

Comments

Projects
None yet
@sfackler
Copy link
Member

sfackler commented Dec 22, 2016

Compiling the postgres-tokio crate at sfackler/rust-postgres@d27518b goes from 5 seconds to 45 seconds on nightly if the two .boxed() calls in the middle of this call chain are removed: https://github.com/sfackler/rust-postgres/blob/d27518ba76d76ccaa59b3ccd63e981bd8bd0ef33/postgres-tokio/src/lib.rs#L342-L408.

Looks like 15 seconds is spent in translation item collection, and 39 seconds is spent in translation:

time: 0.004	parsing
time: 0.005	recursion limit
time: 0.000	crate injection
time: 0.001	plugin loading
time: 0.000	plugin registration
time: 0.238	expansion
time: 0.000	maybe building test harness
time: 0.000	maybe creating a macro crate
time: 0.000	checking for inline asm in case the target doesn't support it
time: 0.000	complete gated feature checking
time: 0.008	early lint checks
time: 0.000	AST validation
time: 0.005	name resolution
time: 0.004	lowering ast -> hir
time: 0.002	indexing hir
time: 0.000	attribute checking
time: 0.001	language item collection
time: 0.001	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.005	compute_incremental_hashes_map
time: 0.000	load_dep_graph
time: 0.000	stability index
time: 0.001	stability checking
time: 0.011	type collecting
time: 0.000	variance inference
time: 0.000	impl wf inference
time: 0.021	coherence checking
time: 0.008	wf checking
time: 0.003	item-types checking
time: 0.500	item-bodies checking
time: 0.000	drop-impl checking
time: 0.003	const checking
time: 0.001	privacy checking
time: 0.000	intrinsic checking
time: 0.000	effect checking
time: 0.001	match checking
time: 0.000	liveness checking
time: 0.002	rvalue checking
time: 0.014	MIR dump
  time: 0.001	SimplifyCfg
  time: 0.002	QualifyAndPromoteConstants
  time: 0.002	TypeckMir
  time: 0.000	SimplifyBranches
  time: 0.001	SimplifyCfg
time: 0.006	MIR cleanup and validation
time: 0.006	borrow checking
time: 0.000	reachability checking
time: 0.000	death checking
time: 0.000	unused lib feature checking
time: 1.366	lint checking
time: 0.000	resolving dependency formats
  time: 0.000	NoLandingPads
  time: 0.001	SimplifyCfg
  time: 0.001	EraseRegions
  time: 0.000	AddCallGuards
  time: 0.008	ElaborateDrops
  time: 0.000	NoLandingPads
  time: 0.001	SimplifyCfg
  time: 0.001	InstCombine
  time: 0.000	Deaggregator
  time: 0.000	CopyPropagation
  time: 0.001	SimplifyLocals
  time: 0.000	AddCallGuards
  time: 0.000	PreTrans
time: 0.015	MIR optimisations
  time: 0.001	write metadata
  time: 15.086	translation item collection
  time: 0.020	codegen unit partitioning
  time: 0.022	internalize symbols
time: 39.376	translation
time: 0.000	assert dep graph
time: 0.000	serialize dep graph
  time: 0.089	llvm function passes [0]
  time: 0.037	llvm module passes [0]
  time: 2.148	codegen passes [0]
  time: 0.001	codegen passes [0]
time: 2.432	LLVM passes
time: 0.000	serialize work products
time: 0.084	linking

Things are significantly worse on 1.13 - 2 minutes in translation!

Some discussion in IRC: https://botbot.me/mozilla/rust-internals/2016-12-22/?msg=78294648&page=1

cc @aturon


UPDATE: #40280 was closed as a duplicate of this. It had the following sample code:

let &(first, B, C, D, E, F, G, H) = self;
let iter = first.buffers_list();
let iter = iter.chain(B.buffers_list());
let iter = iter.chain(C.buffers_list());
let iter = iter.chain(D.buffers_list());
let iter = iter.chain(E.buffers_list());
let iter = iter.chain(F.buffers_list());
let iter = iter.chain(G.buffers_list());
let iter = iter.chain(H.buffers_list());
Box::new(iter)

--nmatsakis

@nikomatsakis

This comment has been minimized.

Copy link
Contributor

nikomatsakis commented Dec 22, 2016

Things are significantly worse on 1.13 - 2 minutes in translation!

This may be the effect of the projection cache.

@aturon

This comment has been minimized.

Copy link
Member

aturon commented Dec 22, 2016

cc @alexcrichton This is obviously a show-stopper for futures.

@nikomatsakis

This comment has been minimized.

Copy link
Contributor

nikomatsakis commented Dec 22, 2016

I can do some profiling. I've had some plans for improving collection/trans that I think may be related. One question to try and answer is what %age of this is just "we are making more code" vs "we are wasting time doing things in trait selection that could be cached". I have observed the latter from time to time and had some thoughts on how to fix it.

@alexcrichton

This comment has been minimized.

Copy link
Member

alexcrichton commented Dec 25, 2016

I've also seen this before, with tokio-socks5 as well. Removing just a handful of the trait objects in that file makes the compile time of the crate shoot from 2.34s to 89.52s (!!)

@dwrensha

This comment has been minimized.

Copy link
Contributor

dwrensha commented Jan 20, 2017

Here's a simple example of something that takes a very long time to compile:

future::ok::<(),()>(()).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(())).and_then(|()| Ok(()));
@nikomatsakis

This comment has been minimized.

Copy link
Contributor

nikomatsakis commented Mar 9, 2017

Closed #40280 as a duplicate, moved some example code into the issue header.

@vorner

This comment has been minimized.

Copy link
Contributor

vorner commented Mar 18, 2017

Just a stupid question ‒ the „translation item collection“, which is one of the two culprits here, is listed in the „MIR optimisations“. Does it really have to happen at all on non-optimised debug build?

@bluss

This comment has been minimized.

Copy link
Contributor

bluss commented Mar 18, 2017

It's natural to read it that way, but the headers are actual after their group, so it's part of translation

@vorner

This comment has been minimized.

Copy link
Contributor

vorner commented Mar 27, 2017

This seems to be hard enough to take some time fixing. So I thought of a workaround, if someone is also interested. It uses the trick with placing trait objects to split the chains of modifiers, but only on testing/debug builds where the compilation speed matters, while it keeps the complex but hopefully faster concrete types in release build:

This one is for streams (that's what I needed), but can obviously work for futures or other things as well:

#[cfg(debug_assertions)]
fn test_boxed<T, E, S>(s: S) -> Box<Stream<Item = T, Error = E>>
    where S: Stream<Item = T, Error = E> + 'static
{
    Box::new(s)
}
#[cfg(not(debug_assertions))]
fn test_boxed<S>(s: S) -> S {
    s
}

(I didn't find any better config option than the debug_assertions, but I hope that one is good enough)

jonhoo added a commit to jonhoo/fantoccini that referenced this issue Jun 20, 2017

Go back to ignoring the tests
Compilation of tests is *really* slow, most likely due to
rust-lang/rust#41696
or
rust-lang/rust#38528
@Mark-Simulacrum

This comment has been minimized.

Copy link
Member

Mark-Simulacrum commented Jul 2, 2017

Nominating in place of #42941. cc @eddyb (nominator)

@jonhoo

This comment has been minimized.

Copy link
Contributor

jonhoo commented Jul 2, 2017

Repeating another bad case from #42941:

extern crate futures;
use futures::{future, IntoFuture, Future};
fn main() {
    let t: std::result::Result<(), ()> = Ok(());
    let f = t
            .into_future()
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()))
            .and_then(|_| future::ok(()));
    f.wait();
}

The code above takes ~750s to compile on my laptop (you can make it shorter/longer by removing/adding .and_then calls):

...
  time: 0.000; rss: 108MB       write metadata
  time: 472.840; rss: 110MB     translation item collection
  time: 0.001; rss: 112MB       codegen unit partitioning
  time: 0.001; rss: 133MB       internalize symbols
time: 732.741; rss: 133MB       translation
...

The extra ~250s is spent between codegen unit partitioning and internalize symbols.

@jonhoo

This comment has been minimized.

Copy link
Contributor

jonhoo commented Jul 6, 2017

Another observation from #42941 about why this is becoming even more important is that the newly-released hyper 0.11 uses futures everywhere, which will likely cause many more programs to use chains of futures like this going forward.

@nikomatsakis

This comment has been minimized.

Copy link
Contributor

nikomatsakis commented Jul 6, 2017

triage: P-high

We are raising to "high priority" to at least do some investigation and try to determine whether revised trait solving strategies will be of use here.

@rust-highfive rust-highfive added P-high and removed I-nominated labels Jul 6, 2017

@nikomatsakis nikomatsakis self-assigned this Jul 6, 2017

jonhoo added a commit to jonhoo/fantoccini that referenced this issue Jul 8, 2017

Box all chains to work around rust-lang/rust#38528
This commit should be reverted once that issue has been resolved.
@arielb1

This comment has been minimized.

Copy link
Contributor

arielb1 commented Aug 10, 2017

status: waiting for niko

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Aug 31, 2017

Bump. This really hurts impl Trait (boxing hides this issue).

@aturon aturon added this to the impl period milestone Sep 4, 2017

@tanriol

This comment has been minimized.

Copy link

tanriol commented Jan 8, 2018

I've tried profiling rustc and getting a backtrace for the generic version by @hcpl above at some random moment of time.

Likely relevant lines from the backtrace
#16 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#17 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#18 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#19 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffeca9f3d0) at librustc/traits/project.rs:1012
#20 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#49 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#50 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#51 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#52 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecaa1550) at librustc/traits/project.rs:1012
#53 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#82 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#83 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecaa3650, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#84 rustc::traits::project::confirm_candidate (obligation=0x7fffecaa3650, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#85 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#86 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#114 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#115 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#116 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#117 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecaa55f0) at librustc/traits/project.rs:1012
#118 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#147 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#148 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#149 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#150 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecaa7770) at librustc/traits/project.rs:1012
#151 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#180 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#181 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#182 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#183 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecaa98f0) at librustc/traits/project.rs:1012
#184 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#213 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#214 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecaab9f0, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#215 rustc::traits::project::confirm_candidate (obligation=0x7fffecaab9f0, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#216 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#217 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#245 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#246 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecaad910, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#247 rustc::traits::project::confirm_candidate (obligation=0x7fffecaad910, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#248 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#249 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#277 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#278 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecaaf830, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#279 rustc::traits::project::confirm_candidate (obligation=0x7fffecaaf830, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#280 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#281 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#309 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#310 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#311 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#312 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecab17d0) at librustc/traits/project.rs:1012
#313 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#342 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#343 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecab38d0, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#344 rustc::traits::project::confirm_candidate (obligation=0x7fffecab38d0, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#345 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#346 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#374 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#375 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecab57f0, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#376 rustc::traits::project::confirm_candidate (obligation=0x7fffecab57f0, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#377 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#378 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#406 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#407 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecab7710, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#408 rustc::traits::project::confirm_candidate (obligation=0x7fffecab7710, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#409 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#410 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#438 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#439 0x00007ffff2f8c276 in rustc::traits::project::confirm_select_candidate (selcx=0x7fffecabfbc0, obligation=0x7fffecab9630, obligation_trait_ref=<optimized out>) at librustc/traits/project.rs:1174
#440 rustc::traits::project::confirm_candidate (obligation=0x7fffecab9630, obligation_trait_ref=<optimized out>, selcx=<optimized out>, candidate=...) at librustc/traits/project.rs:1161
#441 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:878
#442 0x00007ffff2f88038 in rustc::traits::project::opt_normalize_projection_type (selcx=0x7fffecabfbc0, param_env=..., projection_ty=..., cause=..., depth=<optimized out>) at librustc/traits/project.rs:541
--
#470 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#471 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#472 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#473 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecabb5d0) at librustc/traits/project.rs:1012
#474 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817
--
#503 0x00007ffff2f44dbb in rustc::traits::select::SelectionContext::select (self=0x7fffecabfbc0, obligation=0x7fffeca9e488) at librustc/traits/select.rs:526
#504 0x00007ffff3607861 in rustc::traits::project::assemble_candidates_from_impls::{{closure}} () at librustc/traits/project.rs:1013
#505 rustc::infer::InferCtxt::probe (self=<optimized out>, f=...) at librustc/infer/mod.rs:905
#506 0x00007ffff2f8b99f in rustc::traits::project::assemble_candidates_from_impls (selcx=0x7fffecabfbc0, obligation=<optimized out>, obligation_trait_ref=<optimized out>, candidate_set=0x7fffecabd750) at librustc/traits/project.rs:1012
#507 rustc::traits::project::project_type (selcx=<optimized out>, obligation=<optimized out>) at librustc/traits/project.rs:817

The cause in this case seems to be that at every Chain the rustc::traits::project::project_type function calls rustc::traits::select::SelectionContext::select twice: the first time from assemble_candidates_from_impls via InferCtxt::probe, the second time from rustc::traits::project::confirm_candidate. Both calls recurse on the next level, causing the exponential blowup.

@nikomatsakis

This comment has been minimized.

Copy link
Contributor

nikomatsakis commented Jan 22, 2018

Thanks for the profiles everyone, btw, I've been spending a bit more time investigating too but don't yet have any insights to share. =)

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Jan 24, 2018

@nikomatsakis can you share what problem have you stumbled over? Thanks to @tanriol's profile I think the root cause is quite clear; we just need to cache the call to eliminate the blowup. What I'm worrying is that SelectionContext::select does have side effects, and as I don't have much knowledge on projection I don't know if the second (redundant) execution can be easily removed.

@jonhoo

This comment has been minimized.

Copy link
Contributor

jonhoo commented Feb 4, 2018

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 15, 2018

Yeah, so this is related to deeply nested types itself, and it doesn't matter where it appear. As argument, return type, or even just creating on stack triggers this issue. #39684 #43757 should be duplicates.

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 16, 2018

Finding as of today:

The blowup roots from confirm_impl_candidate in select module (not project). Confirming candidate is a non-cachable operation. It then attempts to normalize the type (which doesn't seem to cache too) inside vtable_impl and recurs to next level.

cc @tanriol @nikomatsakis Please check if this clears up some obstacles. Primarily I'm wondering why normalization is continuously performed (maybe due to snapshot?).

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 16, 2018

Okay, I think I've successfully understood the overall picture of this blowup.

First, it's true that we're calling SelectionContext::select twice per iteration. This is what we probably need to reduce to fix the issue.

Second, the blowup occurs in operations that are not currently cached. In confirm_impl_candidate, we create an snapshot and then calls vtable_impl, then impl_or_trait_obligations. It's the place we recur onto next level, and because we are in a snapshot, the unification results are completely discarded after the operation. This is the second cause making the operation non-cachable: unification relies on side effects so it doesn't execute twice, but we revert the changes so it's computing every time.

Adding to that, impl_or_trait_obligations tries to normalize the inner type (?) for each predicate, which sounds like a multiplicative behavior here. However, this is ran without clearing the snapshot, which may make the situation better (it still sounds like an issue to me, though). Also, the reproduction example only used Iterator obligation which is the only one, thus the multiplicative behavior here hasn't been tested yet.

To sum up, we didn't get any short circuits here due to the two factors preventing caching from happening. Next, I'm proposing some solutions below, focusing on fixing the "calling twice" problem:

  1. Try to preserve the snapshot for the impl candidate we resolve. We can reuse it later which eliminates the need of calling confirm_candidate the second time. However, as far I understood I'm not sure if snapshot is designed to be saved beyond scope (it always take a closure for pub APIs).

  2. Do not call confirm_candidates the first time, instead call it only when we're really confirming it. My concern is that this may breaks code that relies on side effects (unification) which I don't understand yet.

  3. This is rather focused on solving the normalization cache, and the idea is quite abstract. We can try to cache normalizations, but I have no idea what we should take as a key.

I need your expertise on this, so we can reach a solution that resolves the issue. Please give me your opinion!

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 17, 2018

Another update: the projection cache actually exists, but we're discarding them every time by wiping the InferCtxt (with snapshots). I have created a diagram to show how this recurs:
Diagram

So basically we need to implement this FIXME:

/// FIXME: we probably also want some sort of cross-infcx cache here to
/// reduce the amount of duplication. Let's see what we get with the Chalk
/// reforms.

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 17, 2018

@arielb1 You seem to have created this FIXME. Can you give me some hints on implementing cross-infcx cache?

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 17, 2018

I have launched a PoC in #48296 and I confirm that the exponential part should be resolved. I still observe some degree of polynomial time algorithms, which makes rustc chokes at about 50 chain().

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 17, 2018

@hcpl I suspect you copied the wrong code for the specialized version above, as I observe the same time-passes behavior and the code lacks main() despite you specify --crate-type bin for the specialized version.

Can you check again, and if possible, provide the correct specialized version code?

@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 18, 2018

Update: although I have fixed the normalization part, the typeck still seems to be exponential on time, and very memory consuming. I'm investigating the cause of this second issue.

bors added a commit that referenced this issue Feb 18, 2018

Auto merge of #48296 - ishitatsuyuki:exp-unblow, r=<try>
[wip] Fix exponential projection complexity on nested types

This implements solution 1 from #38528 (comment).

The code quality is currently extremely poor, but we can improve them during review.

Based on #48315.

Needs changelog. Noticable improvement on compile time is expected.

Fix #38528 (in progress, another exponential blowup exist)
Close #39684
Close #43757
@ishitatsuyuki

This comment has been minimized.

Copy link
Member

ishitatsuyuki commented Feb 18, 2018

I have implemented a fix for the typeck part too, and I believe there's no more exponential algorithms in rustc anymore.

@hcpl

This comment has been minimized.

Copy link

hcpl commented Feb 18, 2018

@ishitatsuyuki the code is correct, but both rustc invocations should have been with --crate-type=lib src/lib.rs (which were assumed to be in different crates). Sorry about that.

I've changed filenames to foo_generic.rs and foo_specialized.rs respectively to better reflect their purpose.

bors added a commit that referenced this issue Feb 18, 2018

Auto merge of #48296 - ishitatsuyuki:exp-unblow, r=<try>
Fix exponential projection complexity on nested types

This implements solution 1 from #38528 (comment).

The code quality is currently extremely poor, but we can improve them during review.

Blocking issues:

- we probably don't want a quadratic deduplication for obligations.
- is there an alternative to deduplication?

Based on #48315.

Needs changelog. Noticable improvement on compile time is expected.

Fix #38528
Close #39684
Close #43757

Manishearth added a commit to Manishearth/rust that referenced this issue Feb 24, 2018

Rollup merge of rust-lang#48296 - ishitatsuyuki:exp-unblow, r=nikomat…
…sakis

Fix exponential projection complexity on nested types

This implements solution 1 from rust-lang#38528 (comment).

The code quality is currently extremely poor, but we can improve them during review.

Blocking issues:

- we probably don't want a quadratic deduplication for obligations.
- is there an alternative to deduplication?

Based on rust-lang#48315.

Needs changelog. Noticable improvement on compile time is expected.

Fix rust-lang#38528
Close rust-lang#39684
Close rust-lang#43757

@bors bors closed this in #48296 Feb 25, 2018

jonhoo added a commit to jonhoo/fantoccini that referenced this issue Feb 27, 2018

Phrohdoh pushed a commit to Phrohdoh/fantoccini that referenced this issue May 11, 2018

Go back to ignoring the tests
Compilation of tests is *really* slow, most likely due to
rust-lang/rust#41696
or
rust-lang/rust#38528

Phrohdoh pushed a commit to Phrohdoh/fantoccini that referenced this issue May 11, 2018

Box all chains to work around rust-lang/rust#38528
This commit should be reverted once that issue has been resolved.

Phrohdoh pushed a commit to Phrohdoh/fantoccini that referenced this issue May 11, 2018

kennytm added a commit to kennytm/rust that referenced this issue Aug 10, 2018

Rollup merge of rust-lang#53025 - ljedrz:debug_asserts_limited, r=varkor
Consider changing assert! to debug_assert! when it calls visit_with

The perf run from rust-lang#52956 revealed that there were 3 benchmarks that benefited most from changing `assert!`s to `debug_assert!`s:

- issue rust-lang#46449: avg -4.7% for -check
- deeply-nested (AKA rust-lang#38528): avg -3.4% for -check
- regression rust-lang#31157: avg -3.2% for -check

I analyzed their fixing PRs and decided to look for potentially heavy assertions in the files they modified. I noticed that all of the non-trivial ones contained indirect calls to `visit_with()`.

It might be a good idea to consider changing `assert!` to `debug_assert!` in those places in order to get the performance wins shown by the benchmarks.

GuillaumeGomez added a commit to GuillaumeGomez/rust that referenced this issue Aug 12, 2018

Rollup merge of rust-lang#53025 - ljedrz:debug_asserts_limited, r=varkor
Consider changing assert! to debug_assert! when it calls visit_with

The perf run from rust-lang#52956 revealed that there were 3 benchmarks that benefited most from changing `assert!`s to `debug_assert!`s:

- issue rust-lang#46449: avg -4.7% for -check
- deeply-nested (AKA rust-lang#38528): avg -3.4% for -check
- regression rust-lang#31157: avg -3.2% for -check

I analyzed their fixing PRs and decided to look for potentially heavy assertions in the files they modified. I noticed that all of the non-trivial ones contained indirect calls to `visit_with()`.

It might be a good idea to consider changing `assert!` to `debug_assert!` in those places in order to get the performance wins shown by the benchmarks.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.