Macro expansion is quadratic in the number of `let` statements.

[huonw]

The following (bash) shell snippet prints let _x: int; /* <number> */ 5000 times, which makes the compiler very unhappy.

$ echo 'fn main() { ' 'let _x: int; /*'{1..5000}'*/' '}'  |  rustc - -Z time-passes
time: 0.056 s   parsing
time: 0.001 s   gated feature checking
time: 0.002 s   std macros injection
time: 0.010 s   configuration 1
time: 9.157 s   expansion
[...]

(the total time is 10.3s.)

First few lines of perf report:

    32.15%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] hash::Writer$SipState::write::hadb05778635375a2fhaT::v0.9$x2dpre
    22.41%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] hashmap::HashMap::bucket_for_key_with_hash::h5b953adb9726637Rjab::v0.9$x2dpre
     9.02%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] hash::Streaming$SipState::result_u64::h1e5a7083bc4c3f6bAga7::v0.9$x2dpre
     8.46%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] hash::Hash$A::hash_keyed::h463e3d8e059f531Zha5::v0.9$x2dpre
     4.20%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] ast_util::get_sctable::he0d4d721b1287a6aH::v0.9$x2dpre
     3.08%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] hashmap::Map$HashMap::find::hf199eda9a92cb3f3CAa3::v0.9$x2dpre
     1.72%     rustc  libsyntax-2bb2d559d93ae8f0-0.9-pre.so  [.] tuple::inner::Eq$__extensions__::eq::h4384d9b129d29aa7Gjas::v0.9$x2dpre            ```

i.e. ~70% of the time is spend on hashing/hashmap look-ups. (cc #10586, although that's not the full problem.)

[eddyb]

From my own tests, I can see 6 * N * N calls to hash::Hash$A::hash_keyed::anon::expr_fn::_9Cacah, where N is the number of let _x: int; statements in main.

4 * N * N from to_bytes::IterBytes$__extensions__::iter_bytes::anon::expr_fn::Uzadaf
2 * N * N from hash::Hash$A::hash_keyed::h463e3d8e059f5319Cac::v0.9$x2dpre

I have two callgrind dumps, one for N = 1000 and another for N = 500, if anyone else wants to take a look at them - I used kcachegrind myself, giving:

[eddyb]

I seems the problem starts with N * N calls to:

ast_util::new_rename::h39e8665ceaa551c1aF::v0.9$x2dpre

originating from 3 * N calls to:

ext::expand::ast_fold$IdentRenamer::fold_ident::hf98b2d77f07645a0v1a9::v0.9$x2dpre

EDIT: IdentRenamer::fold_ident is O(N), and it's called approx. N times, which results in quadratic behavior.

[huonw]

The relevant part of expand makes it clear what's going wrong, it's performing an O(number of idents (in scope?)) fold for every ident in the AST.

cc @jbclements, looks like hygiene comes at a cost and/or needs more caching.

[jbclements]

Yep, everything here makes sense. I'm not surprised that compilation time here is n^2 in the depth of 'let' nesting. It appears to me that compilation of programs that nest identifiers to a depth of 5000 is likely to take an extra ten seconds. There are additional forms of laziness that could be applied to address this problem, but I think that there are other more pressing issues. Agree/disagree?

[pnkfelix]

@jbclements More pressing issues with respect to efficiency of rustc?

Or in getting macro-expansion/hygiene fixed up and/or finalized?

My thinking: As long as the experts are confident that the slowdowns here can be addressed without changing the semantics of macro expansion, then I agree we don't need to fix this immediately. (Except if not fixing it is going to make it difficult to identify other sources of inefficiency within rustc, i.e. by making it difficult to construct similar micro-benchmark inputs to rustc...)

[jbclements]

I see nothing that would prevent (additional) laziness here, though it would be a bit of a headache; I think the most natural solution would be to introduce a "delayed-rename" AST node, so that you can be sure you don't forget to apply the rename everywhere. I take your micro-benchmark comment, though. In this case, I'm guessing that you wouldn't really want a local stack frame with 5K variables, though you might be checking to make sure that they all get optimized away. In that case, I'm guessing that 50 variables would work as well as 5000.

[paulstansifer]

(A bit of context here: the "laziness" is the faster-but-more-complex algorithm described in the classic paper on hygiene in Scheme: http://portal.acm.org/citation.cfm?id=173617.173620 )

[pnkfelix]

I was thinking of Clinger and Rees "Macros that Work", but its been a while since I looked at either carefully, maybe Dybvig "Syntactic Abstraction in Scheme" is the better reference to use at this point.

my memory is that the differences between the papers are most relevant when you start having procedural macros. Rust's macros are still much like Scheme's syntax-rules, and so I hypothesize that one could start from either document and get useful info for attacking this problem.

(If nothing else, at least these links are not behind a paywall.)

[edwardw]

The smoking test time has just been halved: 12563 comment. Most likely, it has to do with improved mtwt::new_rename and / or mtwt::new_mark.

[edwardw]

Another 2x speedup by specializing hasher for mtwt lookup tables, so a total 4x speed gain for now. Still, this is just implementation improvement, not an algorithmic one.

[eddyb]

It matters when the code in question spends minutes in hygiene, thanks @edwardw :D.