Rust: Increasingly slow compilation as more levels of `async` are added in Rust 1.46

[nicholasbishop]

I upgraded from 1.45 to 1.46 today and a crate I'm working on seems to hang forever while compiling. I've attempted to create a somewhat minimal test case. For convenience here's a repo that includes the code below: https://github.com/nicholasbishop/rust146hang

Cargo.toml:

[package]
name = "rust146hang"
version = "0.1.0"
edition = "2018"

[dependencies]
actix-web = "2.0"
bb8 = "0.4"
bb8-postgres = "0.4"
tokio-postgres = "0.5"

src/lib.rs:

use actix_web::{web, HttpResponse, Responder};
use bb8_postgres::PostgresConnectionManager;
use tokio_postgres::NoTls;

type Pool = bb8::Pool<PostgresConnectionManager<NoTls>>;

async fn handle_req_1(pool: &Pool) {
    let conn = pool.get().await.unwrap();
    conn.query_one("", &[]).await.unwrap();
}

async fn handle_req_2(pool: &Pool) {
    handle_req_1(pool).await;
}

async fn handle_req_3(pool: &Pool) {
    handle_req_2(pool).await;
}

async fn handle_req_4(pool: &Pool) {
    handle_req_3(pool).await;
}

async fn handle_req_5(pool: &Pool) {
    handle_req_4(pool).await;
}

async fn handle_req_final(pool: web::Data<Pool>) -> impl Responder {
    handle_req_5(pool.get_ref()).await;
    HttpResponse::Ok().finish()
}

pub fn app_config(config: &mut web::ServiceConfig) {
    config.service(
        web::scope("").route("/api", web::post().to(handle_req_final)),
    );
}

I've found that the slowness seems tied to the depth of the async call chain. In the example code I have a long call chain: handle_req_1 is called by handle_req_2 is called by handle_req_3, etc. Here's the compilation timing I've observed when changing handle_req_final to directly call one of the handle_req_N functions:

handle_req_1 -> 0m12s
handle_req_2 -> 0m28s
handle_req_3 -> 1m06s
handle_req_4 -> 2m18s
handle_req_5 -> 5m01s

These times only include building the rust146hang lib, not the dependencies.

(Caveat: unscientific timings, these are not averaged over multiple
runs or anything.)

$ cargo --version
cargo 1.46.0 (149022b1d 2020-07-17)
$ rustc --version
rustc 1.46.0 (04488afe3 2020-08-24)

[jyn514]

Possible duplicate of #72408?

[kellerkindt]

Noticed the same issue. A crate that compiled in 1.45 in about 4 minutes, seems to compile for forever in 1.46 (rustc utilized 100% of one core for at least 25minutes before I cancelled it)

EDIT: 2 hours of compilation later, and no result yet

[jyn514]

Interestingly, this only happens with cargo build, not cargo check.

[ojeda]

Caveat: unscientific timings, these are not averaged over multiple runs or anything.

Well, it is a nearly perfect exponential fit!

[kellerkindt]

FYI, issue (remains) present in

• rustc 1.46.0 (04488afe3 2020-08-24)
• rustc 1.47.0-beta.1 (0f91f5c28 2020-08-25)
• rustc 1.48.0-nightly (397b390cc 2020-08-27)

It seems to not matter whether --release is set

[kellerkindt]

Got you an example on the playground (updated)

Just adjust the number for the macro call here:

async fn f() {
    //  9: ~0.68s
    // 10: ~0.83s
    // 11: ~1.34s
    // 12: ~2.68s
    // 13: ~5.24s reached length limit -> #![type_length_limit="1228764"]
    // 14: ~7.89s reached length limit -> #![type_length_limit="2457564"]
    // 15: /playground/tools/entrypoint.sh: line 11:     7 Killed                  timeout --signal=KILL ${timeout} "$@"
    async_recursive!(9, println!("done"))
}

EDIT: My crate that "compiles forever" just failed after nearly 3hours of compiling. I don't know what caused the SIGKILL, but it wasn't me at least.

$ time cargo test -p common --release

...
error: could not compile `messages`.

Caused by:
  process didn't exit successfully: `rustc --crate-name messages --edition=2018 messages/src/lib.rs --error-format=json --json=diagnostic-rendered-ansi,artifacts --crate-type lib --emit=dep-info,metadata,link -C opt-level=3 -C metadata=0c091483b2a87fc1 -C extra-filename=-0c091483b2a87fc1 --out-dir /tmp/cargo-target/release/deps -L dependency=/tmp/cargo-target/release/deps --extern asn1rs=/tmp/cargo-target/release/deps/libasn1rs-7f0d3cb210b4f673.rmeta --extern futures=/tmp/cargo-target/release/deps/libfutures-3a0be1c37a28e9a8.rmeta --extern serde=/tmp/cargo-target/release/deps/libserde-d9d8359d95432fa4.rmeta --extern serde_derive=/tmp/cargo-target/release/deps/libserde_derive-26bde9a45b227be1.so --extern tokio=/tmp/cargo-target/release/deps/libtokio-c76c350ce32195b9.rmeta --extern tokio_postgres=/tmp/cargo-target/release/deps/libtokio_postgres-e63ce98e1edc8138.rmeta` (signal: 9, SIGKILL: kill)

real    161m7,663s
user    169m13,774s
sys     0m35,055s

EDIT2: Updated example on the playground, old version
EDIT3: Updated example on the playground, old version
EDIT4: For your local testing

Create the file template.rs:

#![recursion_limit="2048"]
#![type_length_limit="12457564"]

macro_rules! async_recursive {
    (29, $inner:expr) => { async { async_recursive!(28, $inner) }.await };
    (28, $inner:expr) => { async { async_recursive!(27, $inner) }.await };
    (27, $inner:expr) => { async { async_recursive!(26, $inner) }.await };
    (26, $inner:expr) => { async { async_recursive!(25, $inner) }.await };
    (25, $inner:expr) => { async { async_recursive!(24, $inner) }.await };
    (24, $inner:expr) => { async { async_recursive!(23, $inner) }.await };
    (23, $inner:expr) => { async { async_recursive!(22, $inner) }.await };
    (22, $inner:expr) => { async { async_recursive!(21, $inner) }.await };
    (21, $inner:expr) => { async { async_recursive!(20, $inner) }.await };
    (20, $inner:expr) => { async { async_recursive!(19, $inner) }.await };

    (19, $inner:expr) => { async { async_recursive!(18, $inner) }.await };
    (18, $inner:expr) => { async { async_recursive!(17, $inner) }.await };
    (17, $inner:expr) => { async { async_recursive!(16, $inner) }.await };
    (16, $inner:expr) => { async { async_recursive!(15, $inner) }.await };
    (15, $inner:expr) => { async { async_recursive!(14, $inner) }.await };
    (14, $inner:expr) => { async { async_recursive!(13, $inner) }.await };
    (13, $inner:expr) => { async { async_recursive!(12, $inner) }.await };
    (12, $inner:expr) => { async { async_recursive!(11, $inner) }.await };
    (11, $inner:expr) => { async { async_recursive!(10, $inner) }.await };
    (10, $inner:expr) => { async { async_recursive!(9, $inner) }.await };

    (9, $inner:expr) => { async { async_recursive!(8, $inner) }.await };
    (8, $inner:expr) => { async { async_recursive!(7, $inner) }.await };
    (7, $inner:expr) => { async { async_recursive!(6, $inner) }.await };
    (6, $inner:expr) => { async { async_recursive!(5, $inner) }.await };
    (5, $inner:expr) => { async { async_recursive!(4, $inner) }.await };
    (4, $inner:expr) => { async { async_recursive!(3, $inner) }.await };
    (3, $inner:expr) => { async { async_recursive!(2, $inner) }.await };
    (2, $inner:expr) => { async { async_recursive!(1, $inner) }.await };
    (1, $inner:expr) => { async { async_recursive!(0, $inner) }.await };
    (0, $inner:expr) => { async { $inner }.await };
}

async fn f() {
    //  9: ~0.68s
    // 10: ~0.83s
    // 11: ~1.34s
    // 12: ~2.68s
    // 13: ~5.24s reached length limit -> #![type_length_limit="1228764"]
    // 14: ~7.89s reached length limit -> #![type_length_limit="2457564"]
    // 15: /playground/tools/entrypoint.sh: line 11:     7 Killed                  timeout --signal=KILL ${timeout} "$@"
    async_recursive!(REPLACE_ME, println!("done"))
}

fn main() {
    let _ = f();
}

Then run:

for n in $(seq 29); do sed "s/REPLACE_ME/$n/g" template.rs > main.rs && echo "== Level $n" && time rustc --edition 2018 main.rs; done

Sample output, looks exponential:

== Level 1

real    0m0,217s
user    0m0,149s
sys 0m0,038s
== Level 2

real    0m0,216s
user    0m0,169s
sys 0m0,039s
== Level 3

real    0m0,138s
user    0m0,132s
sys 0m0,017s
== Level 4

real    0m0,149s
user    0m0,129s
sys 0m0,029s
== Level 5

real    0m0,165s
user    0m0,127s
sys 0m0,047s
== Level 6

real    0m0,178s
user    0m0,165s
sys 0m0,022s
== Level 7

real    0m0,168s
user    0m0,141s
sys 0m0,035s
== Level 8

real    0m0,204s
user    0m0,178s
sys 0m0,038s
== Level 9

real    0m0,249s
user    0m0,214s
sys 0m0,046s
== Level 10

real    0m0,336s
user    0m0,319s
sys 0m0,028s
== Level 11

real    0m0,583s
user    0m0,575s
sys 0m0,016s
== Level 12

real    0m0,946s
user    0m0,927s
sys 0m0,030s
== Level 13

real    0m1,713s
user    0m1,674s
sys 0m0,036s
== Level 14

real    0m3,812s
user    0m3,667s
sys 0m0,079s
== Level 15

real    0m6,901s
user    0m6,807s
sys 0m0,055s
== Level 16

real    0m14,814s
user    0m14,599s
sys 0m0,156s
== Level 17

real    0m29,575s
user    0m28,952s
sys 0m0,312s
== Level 18

real    0m59,365s
user    0m58,339s
sys 0m0,800s

[kellerkindt]

Hmm, there might actually be two separate issues here? The example I provided above behaves the same on rustc 1.43.0 to current (1.42.0 and before are even slower). But the repo provided by @nicholasbishop and my local project compile fast on <=1.45.* and really slow with 1.46 and later.

[jyn514]

Sounds like the first example might be https://github.com/rust-lang/rust/issues/72408, then.

[kellerkindt]

I am able to somewhat limit it to argument parameters (being references! passing ownership has no effect).
In the following example the compilation time difference between 1.45 and 1.46 is about 2x.

Create the file template.rs:

#![recursion_limit="2048"]
#![type_length_limit="112457564"]

pub async fn h0(v: &String, x: &u64) { println!("{} {}", v, x) }
pub async fn h1(v: &String, x: &u64) { h0(v, x).await }
pub async fn h2(v: &String, x: &u64) { h1(v, x).await }
pub async fn h3(v: &String, x: &u64) { h2(v, x).await }
pub async fn h4(v: &String, x: &u64) { h3(v, x).await }
pub async fn h5(v: &String, x: &u64) { h4(v, x).await }
pub async fn h6(v: &String, x: &u64) { h5(v, x).await }
pub async fn h7(v: &String, x: &u64) { h6(v, x).await }
pub async fn h8(v: &String, x: &u64) { h7(v, x).await }
pub async fn h9(v: &String, x: &u64) { h8(v, x).await }

pub async fn h10(v: &String, x: &u64) { h9(v, x).await }
pub async fn h11(v: &String, x: &u64) { h10(v, x).await }
pub async fn h12(v: &String, x: &u64) { h11(v, x).await }
pub async fn h13(v: &String, x: &u64) { h12(v, x).await }
pub async fn h14(v: &String, x: &u64) { h13(v, x).await }
pub async fn h15(v: &String, x: &u64) { h14(v, x).await }
pub async fn h16(v: &String, x: &u64) { h15(v, x).await }
pub async fn h17(v: &String, x: &u64) { h16(v, x).await }
pub async fn h18(v: &String, x: &u64) { h17(v, x).await }
pub async fn h19(v: &String, x: &u64) { h18(v, x).await }


macro_rules! async_recursive {
    (29, $inner:expr) => { async { async_recursive!(28, $inner) }.await };
    (28, $inner:expr) => { async { async_recursive!(27, $inner) }.await };
    (27, $inner:expr) => { async { async_recursive!(26, $inner) }.await };
    (26, $inner:expr) => { async { async_recursive!(25, $inner) }.await };
    (25, $inner:expr) => { async { async_recursive!(24, $inner) }.await };
    (24, $inner:expr) => { async { async_recursive!(23, $inner) }.await };
    (23, $inner:expr) => { async { async_recursive!(22, $inner) }.await };
    (22, $inner:expr) => { async { async_recursive!(21, $inner) }.await };
    (21, $inner:expr) => { async { async_recursive!(20, $inner) }.await };
    (20, $inner:expr) => { async { async_recursive!(19, $inner) }.await };

    (19, $inner:expr) => { async { async_recursive!(18, $inner) }.await };
    (18, $inner:expr) => { async { async_recursive!(17, $inner) }.await };
    (17, $inner:expr) => { async { async_recursive!(16, $inner) }.await };
    (16, $inner:expr) => { async { async_recursive!(15, $inner) }.await };
    (15, $inner:expr) => { async { async_recursive!(14, $inner) }.await };
    (14, $inner:expr) => { async { async_recursive!(13, $inner) }.await };
    (13, $inner:expr) => { async { async_recursive!(12, $inner) }.await };
    (12, $inner:expr) => { async { async_recursive!(11, $inner) }.await };
    (11, $inner:expr) => { async { async_recursive!(10, $inner) }.await };
    (10, $inner:expr) => { async { async_recursive!(9, $inner) }.await };

    (9, $inner:expr) => { async { async_recursive!(8, $inner) }.await };
    (8, $inner:expr) => { async { async_recursive!(7, $inner) }.await };
    (7, $inner:expr) => { async { async_recursive!(6, $inner) }.await };
    (6, $inner:expr) => { async { async_recursive!(5, $inner) }.await };
    (5, $inner:expr) => { async { async_recursive!(4, $inner) }.await };
    (4, $inner:expr) => { async { async_recursive!(3, $inner) }.await };
    (3, $inner:expr) => { async { async_recursive!(2, $inner) }.await };
    (2, $inner:expr) => { async { async_recursive!(1, $inner) }.await };
    (1, $inner:expr) => { async { async_recursive!(0, $inner) }.await };
    (0, $inner:expr) => { async { h19(&String::from("owo"), &0).await; $inner }.await };
}

async fn f() {
    async_recursive!(REPLACE_ME, println!("hello"));
}

fn main() {
    let _ = f();
}

The execute:

for n in $(seq 15); do sed "s/REPLACE_ME/$n/g" template.rs > main.rs && echo && echo && echo && echo "== Level $n @ 1.45.0" && time rustc +1.45.0 --edition 2018 main.rs && echo "== Level $n @ 1.46.0" && time rustc --edition 2018 main.rs; done

Which results in:

== Level 1 @ 1.45.0

real    0m0,266s
user    0m0,241s
sys 0m0,037s
== Level 1 @ 1.46.0

real    0m0,181s
user    0m0,172s
sys 0m0,039s



== Level 2 @ 1.45.0

real    0m0,218s
user    0m0,212s
sys 0m0,045s
== Level 2 @ 1.46.0

real    0m0,182s
user    0m0,177s
sys 0m0,034s



== Level 3 @ 1.45.0

real    0m0,199s
user    0m0,179s
sys 0m0,051s
== Level 3 @ 1.46.0

real    0m0,191s
user    0m0,179s
sys 0m0,041s



== Level 4 @ 1.45.0

real    0m0,202s
user    0m0,197s
sys 0m0,035s
== Level 4 @ 1.46.0

real    0m0,213s
user    0m0,209s
sys 0m0,039s



== Level 5 @ 1.45.0

real    0m0,207s
user    0m0,212s
sys 0m0,024s
== Level 5 @ 1.46.0

real    0m0,206s
user    0m0,189s
sys 0m0,048s



== Level 6 @ 1.45.0

real    0m0,220s
user    0m0,206s
sys 0m0,044s
== Level 6 @ 1.46.0

real    0m0,230s
user    0m0,227s
sys 0m0,033s



== Level 7 @ 1.45.0

real    0m0,269s
user    0m0,251s
sys 0m0,048s
== Level 7 @ 1.46.0

real    0m0,271s
user    0m0,259s
sys 0m0,043s



== Level 8 @ 1.45.0

real    0m0,288s
user    0m0,260s
sys 0m0,059s
== Level 8 @ 1.46.0

real    0m0,373s
user    0m0,353s
sys 0m0,049s



== Level 9 @ 1.45.0

real    0m0,371s
user    0m0,368s
sys 0m0,034s
== Level 9 @ 1.46.0

real    0m0,540s
user    0m0,550s
sys 0m0,020s



== Level 10 @ 1.45.0

real    0m0,576s
user    0m0,583s
sys 0m0,024s
== Level 10 @ 1.46.0

real    0m0,860s
user    0m0,851s
sys 0m0,041s



== Level 11 @ 1.45.0

real    0m0,954s
user    0m0,941s
sys 0m0,044s
== Level 11 @ 1.46.0

real    0m1,588s
user    0m1,581s
sys 0m0,036s



== Level 12 @ 1.45.0

real    0m1,721s
user    0m1,696s
sys 0m0,040s
== Level 12 @ 1.46.0

real    0m3,168s
user    0m3,122s
sys 0m0,057s



== Level 13 @ 1.45.0

real    0m3,406s
user    0m3,329s
sys 0m0,070s
== Level 13 @ 1.46.0

real    0m5,861s
user    0m5,831s
sys 0m0,044s



== Level 14 @ 1.45.0

real    0m6,738s
user    0m6,699s
sys 0m0,060s
== Level 14 @ 1.46.0

real    0m11,734s
user    0m11,679s
sys 0m0,064s



== Level 15 @ 1.45.0

real    0m13,908s
user    0m13,833s
sys 0m0,103s
== Level 15 @ 1.46.0

real    0m23,823s
user    0m23,744s
sys 0m0,080s

EDIT: The example provided by @nicholasbishop can be simplified further:

use actix_web::{web, HttpResponse, Responder};
use bb8_postgres::PostgresConnectionManager;
use tokio_postgres::NoTls;


type Pool = bb8::Pool<PostgresConnectionManager<NoTls>>;

async fn handle_req_1(pool: &Pool) {
    let conn = pool.get().await.unwrap();
    conn.query_one("", &[]).await.unwrap();
}


async fn handle_req_final(pool: web::Data<Pool>) -> impl Responder {
    handle_req_1(pool.get_ref()).await;
    HttpResponse::Ok().finish()
}

pub fn app_config() {
    let _ = web::post().to(handle_req_final);
}

With dependencies pre-built, this takes about 0.5s with rustc 1.45.0 and 4.5s with rustc 1.46.0.

[LeSeulArtichaut]

I think @kellerkindt's example above should be good enough to do some bisection, but of course it would be great if we could minimize this further.

@rustbot ping cleanup

[rustbot]

Hey Cleanup Crew ICE-breakers! This bug has been identified as a good
"Cleanup ICE-breaking candidate". In case it's useful, here are some
[instructions] for tackling these sorts of bugs. Maybe take a look?
Thanks! <3

cc @AminArria @camelid @chrissimpkins @contrun @DutchGhost @elshize @ethanboxx @h-michael @HallerPatrick @hdhoang @hellow554 @imtsuki @kanru @KarlK90 @LeSeulArtichaut @MAdrianMattocks @matheus-consoli @mental32 @nmccarty @Noah-Kennedy @pard68 @PeytonT @pierreN @Redblueflame @RobbieClarken @RobertoSnap @robjtede @SarthakSingh31 @senden9 @shekohex @sinato @spastorino @turboladen @woshilapin @yerke

[Nicholas-Baron]

@kellerkindt I think you credited the example incorrectly. It should go to @nicholasbishop.

[algesten]

I think I have a related error. My lib compiled fine under 1.45, but cargo build (and test) breaks under 1.46.

error: reached the type-length limit while instantiating `<std::boxed::Box<std::future::fr..., ()}]>>, ()}]>, ()}]>>>>>::into`
   --> /Users/martin/.rustup/toolchains/stable-x86_64-apple-darwin/lib/rustlib/src/rust/src/libcore/convert/mod.rs:559:5
    |
559 | /     fn into(self) -> U {
560 | |         U::from(self)
561 | |     }
    | |_____^
    |
    = note: consider adding a `#![type_length_limit="1527629"]` attribute to your crate

The code is here, master branch is failing

[kellerkindt]

Yeah, this might be related to #54540. (https://github.com/rust-lang/rust/issues/54540#issuecomment-678827051)

[kellerkindt]

Did my own bisection (4 times). Each time it identified the regression in nightly-2020-08-14.

One time (probably a timing error/blurp?) the result was:

searched nightlies: from nightly-2020-05-03 to nightly-2020-08-27
regressed nightly: nightly-2020-08-14
searched commits: from https://github.com/rust-lang/rust/commit/576d27c5a6c80cd39ef57d7398831d8e177573cc to https://github.com/rust-lang/rust/commit/81dc88f88f92ba8ad7465f9cba10c12d3a7b70f1
regressed commit: https://github.com/rust-lang/rust/commit/a0c290f951076d781b0ff08370445517446cee05

bisected with cargo-bisect-rustc v0.5.2

Host triple: x86_64-unknown-linux-gnu
Reproduce with:

cargo bisect-rustc --test-dir=. --start 2020-05-03 --end 2020-08-27 

Three times the result was (the same as https://github.com/rust-lang/rust/issues/54540#issuecomment-676797873) :

searched nightlies: from nightly-2020-05-03 to nightly-2020-08-27
regressed nightly: nightly-2020-08-14
searched commits: from https://github.com/rust-lang/rust/commit/576d27c5a6c80cd39ef57d7398831d8e177573cc to https://github.com/rust-lang/rust/commit/81dc88f88f92ba8ad7465f9cba10c12d3a7b70f1
regressed commit: https://github.com/rust-lang/rust/commit/0a49057dd35d9bd2fcc9760a054809c30eee2a58

bisected with cargo-bisect-rustc v0.5.2

Host triple: x86_64-unknown-linux-gnu
Reproduce with:

cargo bisect-rustc --test-dir=. --start 2020-05-03 --end 2020-08-27 

bash script

You may need to tweak this, depending on your local machine.

#!/bin/bash
set -e
rustc --version >> result.txt
echo "Test 1" >> result.txt
time timeout 7 rustc --edition 2018 src/main.rs
echo "Test 2" >> result.txt
time timeout 7 rustc --edition 2018 src/main.rs
echo "Test 3" >> result.txt
time timeout 7 rustc --edition 2018 src/main.rs

rust code

#![recursion_limit="2048"]
#![type_length_limit="112457564"]


pub async fn h0(v: &String, x: &u64) { println!("{} {}", v, x) }
pub async fn h1(v: &String, x: &u64) { h0(v, x).await }
pub async fn h2(v: &String, x: &u64) { h1(v, x).await }
pub async fn h3(v: &String, x: &u64) { h2(v, x).await }
pub async fn h4(v: &String, x: &u64) { h3(v, x).await }
pub async fn h5(v: &String, x: &u64) { h4(v, x).await }
pub async fn h6(v: &String, x: &u64) { h5(v, x).await }
pub async fn h7(v: &String, x: &u64) { h6(v, x).await }
pub async fn h8(v: &String, x: &u64) { h7(v, x).await }
pub async fn h9(v: &String, x: &u64) { h8(v, x).await }

pub async fn h10(v: &String, x: &u64) { h9(v, x).await }
pub async fn h11(v: &String, x: &u64) { h10(v, x).await }
pub async fn h12(v: &String, x: &u64) { h11(v, x).await }
pub async fn h13(v: &String, x: &u64) { h12(v, x).await }
pub async fn h14(v: &String, x: &u64) { h13(v, x).await }
pub async fn h15(v: &String, x: &u64) { h14(v, x).await }
pub async fn h16(v: &String, x: &u64) { h15(v, x).await }
pub async fn h17(v: &String, x: &u64) { h16(v, x).await }
pub async fn h18(v: &String, x: &u64) { h17(v, x).await }
pub async fn h19(v: &String, x: &u64) { h18(v, x).await }


macro_rules! async_recursive {
    (29, $inner:expr) => { async { async_recursive!(28, $inner) }.await };
    (28, $inner:expr) => { async { async_recursive!(27, $inner) }.await };
    (27, $inner:expr) => { async { async_recursive!(26, $inner) }.await };
    (26, $inner:expr) => { async { async_recursive!(25, $inner) }.await };
    (25, $inner:expr) => { async { async_recursive!(24, $inner) }.await };
    (24, $inner:expr) => { async { async_recursive!(23, $inner) }.await };
    (23, $inner:expr) => { async { async_recursive!(22, $inner) }.await };
    (22, $inner:expr) => { async { async_recursive!(21, $inner) }.await };
    (21, $inner:expr) => { async { async_recursive!(20, $inner) }.await };
    (20, $inner:expr) => { async { async_recursive!(19, $inner) }.await };

    (19, $inner:expr) => { async { async_recursive!(18, $inner) }.await };
    (18, $inner:expr) => { async { async_recursive!(17, $inner) }.await };
    (17, $inner:expr) => { async { async_recursive!(16, $inner) }.await };
    (16, $inner:expr) => { async { async_recursive!(15, $inner) }.await };
    (15, $inner:expr) => { async { async_recursive!(14, $inner) }.await };
    (14, $inner:expr) => { async { async_recursive!(13, $inner) }.await };
    (13, $inner:expr) => { async { async_recursive!(12, $inner) }.await };
    (12, $inner:expr) => { async { async_recursive!(11, $inner) }.await };
    (11, $inner:expr) => { async { async_recursive!(10, $inner) }.await };
    (10, $inner:expr) => { async { async_recursive!(9, $inner) }.await };

    (9, $inner:expr) => { async { async_recursive!(8, $inner) }.await };
    (8, $inner:expr) => { async { async_recursive!(7, $inner) }.await };
    (7, $inner:expr) => { async { async_recursive!(6, $inner) }.await };
    (6, $inner:expr) => { async { async_recursive!(5, $inner) }.await };
    (5, $inner:expr) => { async { async_recursive!(4, $inner) }.await };
    (4, $inner:expr) => { async { async_recursive!(3, $inner) }.await };
    (3, $inner:expr) => { async { async_recursive!(2, $inner) }.await };
    (2, $inner:expr) => { async { async_recursive!(1, $inner) }.await };
    (1, $inner:expr) => { async { async_recursive!(0, $inner) }.await };
    (0, $inner:expr) => { async { h19(&String::from("owo"), &0).await; $inner }.await };
}

async fn f() {
    async_recursive!(12, println!("hello"));
    async_recursive!(12, println!("hello"));
    async_recursive!(12, println!("hello"));
}

fn main() {
    let _ = f();
}

EDIT: I also ran the bisection on the original example of @nicholasbishop (which either compiles in finite time with 1.45.x - ~22s for me - or takes forever with 1.46.0), with the same result:

searched nightlies: from nightly-2020-05-03 to nightly-2020-08-27
regressed nightly: nightly-2020-08-14
searched commits: from https://github.com/rust-lang/rust/commit/576d27c5a6c80cd39ef57d7398831d8e177573cc to https://github.com/rust-lang/rust/commit/81dc88f88f92ba8ad7465f9cba10c12d3a7b70f1
regressed commit: https://github.com/rust-lang/rust/commit/0a49057dd35d9bd2fcc9760a054809c30eee2a58

bisected with cargo-bisect-rustc v0.5.2

Host triple: x86_64-unknown-linux-gnu
Reproduce with:

cargo bisect-rustc --test-dir=. --start 2020-05-03 --end 2020-08-27 

bash script

You may need to tweak this, depending on your local machine.

#!/bin/bash
set -e
cargo clean
time timeout 35 cargo build

[algesten]

I bisected here https://github.com/algesten/hreq/issues/11

It pointed to #0a49057

---

Regression in 0a49057dd35d9bd2fcc9760a054809c30eee2a58

---

searched nightlies: from nightly-2020-08-12 to nightly-2020-08-15
regressed nightly: nightly-2020-08-14
searched commits: from https://github.com/rust-lang/rust/commit/576d27c5a6c80cd39ef57d7398831d8e177573cc to https://github.com/rust-lang/rust/commit/81dc88f88f92ba8ad7465f9cba10c12d3a7b70f1
regressed commit: https://github.com/rust-lang/rust/commit/0a49057dd35d9bd2fcc9760a054809c30eee2a58

bisected with cargo-bisect-rustc v0.5.2

Host triple: x86_64-apple-darwin
Reproduce with:

cargo bisect-rustc --start=2020-08-12 --end=2020-08-15 

[jyn514]

cc @lcnr, this regressed in https://github.com/rust-lang/rust/pull/75443

[jyn514]

https://github.com/rust-lang/rust/issues/75992#issuecomment-682595159 is an MCVE.

[lcnr]

Will spend some time looking into this this week, cc @eddyb @nikomatsakis, this seems like an unfortunate side effect of looking into opaque types and I don't yet have a good idea on how to fix this

[Dylan-DPC]

Marking this as P-[high] based on the wg-prioritization discussion

[trevyn]

76928 which triggered the bors auto-close says it only “partially fixes #75992” — should this be kept open?

[lcnr]

Not sure, in my local tests the repro compiled faster with this change than with 1.45.1.

So looking at the issue title I think it's fine to close this once someone else verifies that it is fixed for them.
"Increasingly slow compilation as more levels of async are added in Rust 1.46"

(the fix is not part of the current nightly, so this will have to wait until tomorrow unless someone wants to download the master branch)

72412 fixed the type length limit increases, so I guess there isn't much we have to do here anymore

[yotamofek]

For what it's worth:

I have a (somewhat) big workspace with one binary (specifically an HTTP REST server implemented with actix-web) that used to take ~10mins for a clean build, but has been taking around ~30mins since (IINM) the nightly version for August 13th.

After reading @lcnr 's comment, I pulled in the latest commit from master and built a local copy of the compiler. The git head is at e62323df22ecf9c163023132d17b7114f68b72e8 , which according to the log contains the merged #76928 . Unfortunately, the compile times have not improved at all! Still around ~30mins.

But, this very unscientific experience should be taken with a molecule of salt:

• I spent a couple of hours trying to minimize my "problematic" binary into something close to an MCVE, but it is far too intertwined with the rest of my workspace crates (which I can't publish, unfortunately). Maybe my problems have nothing to do with the issue at hand.
• I consider myself a somewhat experienced Rust dev, but this has been my first time actually compiling rust and trying to compile my code using a self-built version of rustc. I tried to double-check everything I did on each step, but might have made some mistakes along the way :)

Also wanted to just personally say thank you to all the various contributors around this issue and the rust ecosystem in general, it's pretty amazing to see this community at work.

[lcnr]

We should probably feature this more prominently, but I once again forgot about https://github.com/kennytm/rustup-toolchain-install-master, which is a great tool to get the current master build without having to build rust locally.

[lcnr]

https://github.com/nicholasbishop/rust146hang compiles for me in 3m 21s with all dependencies
With version 1.44.1 this only takes 23.45s, meaning that there's still something else we need to fix here

https://github.com/rust-lang/rust/issues/75992#issuecomment-682595159 with async_recursive!(14, println!("hello"));
takes 1.58s using the master branch and 5.88s using 1.44.1, so there is probably something else going on here.

[steadylearner]

I tested with this project and it did take almost forever to show the error at console.

Error (signal:9 SIGKILL: kill)

You can find the project at GitHub. - async await code is used here.

The Rust versions used for this was 1.46

The reddit post for this.

[Lesiuk]

My actix-web microservice even using todays nightly is using 10 times more ram to compile than 1.45.2 so I am stuck using 1.45.2 until it's fixed.

[trevyn]

@kornelski Which test case? There seem to be a couple different things going on here.

[lcnr]

To sum it up there were more than one issue which needed a fix here, https://github.com/rust-lang/rust/issues/75992#issuecomment-682595159 only required fixing one of them.

This means that I am now once again stuck without a good test case. It would be nice to find a MVCE here which regressed with 1.46 and is still not fixed on the current nightly.

it might be worth it to try and minimize https://github.com/steadylearner/throwaway as it is not yet fixed on the currently nightly.

@rustbot ping cleanup

[rustbot]

Hey Cleanup Crew ICE-breakers! This bug has been identified as a good
"Cleanup ICE-breaking candidate". In case it's useful, here are some
[instructions] for tackling these sorts of bugs. Maybe take a look?
Thanks! <3

cc @AminArria @camelid @chrissimpkins @contrun @DutchGhost @elshize @ethanboxx @h-michael @HallerPatrick @hdhoang @hellow554 @imtsuki @JamesPatrickGill @kanru @KarlK90 @LeSeulArtichaut @MAdrianMattocks @matheus-consoli @mental32 @nmccarty @Noah-Kennedy @pard68 @PeytonT @pierreN @Redblueflame @RobbieClarken @RobertoSnap @robjtede @SarthakSingh31 @senden9 @shekohex @sinato @smmalis37 @spastorino @Stupremee @tamuhey @turboladen @woshilapin @yerke

[max-frai]

Still very long compile time for base actix-web async handler which calls inside any async function.

[jyn514]

@max-frai can you please post your code so we can try to replicate the slow down?

[Lesiuk]

Memory usage during compilation of my very small actix-web microservice using 1.49.0-nightly (a1dfd2490 2020-10-05) and It couldn't finish because went OOM. 1.45.2 can compile it using less than 1 GB.

EDIT: I will try to prepare minimal reproduction.

[MonliH]

Not sure how useful this is, but seems there is an MVCE mentioned in actix/actix-web/1688. Heres the MVCE.

[Lesiuk]

It looks like https://github.com/maicallist/rust_mongo_558 reproduces the issue. I am also using mongodb with actix-web.

[lcnr]

Not sure how useful this is, but seems there is an MVCE mentioned in actix/actix-web/1688. Heres the MVCE.

Thanks! It is still a bit annoying that this MVCE depends on actix-web and mongodb, so it would be really nice if we were able to somehow remove these dependencies and instead inline the required functions

[ThaFireDragonOfDeath]

I'm using tokio-postgres with actix-web and have the same problem.
I compiled this and it took about 20 minutes (without the dependency's).
With rust 1.45.2 it took about 13 seconds (without dependency's).
I'm using decent hardware (Ryzen 3400g, 16 GB RAM and a Samsung NVMe SSD) and the rustc 1.49.0-nightly (b1af43bc6 2020-10-10) compiler. Rust 1.46 stable has the same problem.

I think I will stay on 1.45.2 until this is fixed.

[Noah-Kennedy]

I have a project where I am using tokio-postgres on actix web. I ran the code on 2020-10-8 and observed the following results:

stable  1.47.0  dev     = 8m 05s
stable  1.47.0  release = 9m 19s

stable  1.46.0  dev     = 9m 44s
stable  1.46.0  release = 10m 55s

beta    1.48.0  dev     = 8m 29s
beta    1.48.0  release = 10m 03s

stable  1.45.2  dev     = 0m 9.09s
stable  1.45.2  release = 1m 56s

nightly 1.49.0  dev     = 8m 29s
nightly 1.49.0  release = 9m 55s

I will keep running nightly in my CI to see if anything improves it.

EDIT:
Hardware is Ryzen 9 3900X, OS is the latest Arch Linux.

[chebykinn]

I can confirm the last two cases, with tokio-postgres and actix i've got up to 5 minutes of compile time with stable > 1.45.2 and with the latest nightly. With rustc 1.45.2 my project compiles in 1 minute.

[jyn514]

Hello everyone, thanks for the examples. We have enough examples of large projects failing to compile, what we need now is small self-contained examples that don't depend on tokio or actix.

[Noah-Kennedy]

@jyn514 I'll try and get one set up then.

[camelid]

Cc @lcnr

[enzious]

Any suggestions on making an MVCE based on that commit? What is the MVCE used for? Testing a fix?

[jyn514]

An MCVE is used to see _what_ makes the compiler slow, not just for testing that the fix works. It helps people working on the compiler to understand exactly what's going wrong; actix is a big project and it's not really feasible to look at every line one at a time.

[LeSeulArtichaut]

@pnkfelix had written a blog post about frequent minimization patterns, I think it might help you.

Also, the reproduction we have right now is pretty large, don't feel obliged to minimize it alone. You can open e.g. a repository to publish your progress and get help from others

[camelid]

This repo seems to reproduce the issue as well -- it's from issue #78125.

[enzious]

This repo seems to reproduce the issue as well -- it's from issue #78125.

Problem is, from a compiler developer standpoint, this isn't a very simple reproduction. Even if you pull out the actix-web crate, the mongodb async codebase is pretty big too.

[enzious]

@jyn514 Since you're here.

Since this broke compilation on stable projects, and we know the culprit commit, could we revert the offending commit until this issue is resolved properly? Or is that a problem because we went stable with this commit? I feel like breaking older valid stable code is a bigger issue than breaking newer stable code.

And clarifying, my definition of broken code isn't airtight. For my project, I can't compile at all since my memory runs out with 32GiB (30GiB of it free before compilation)

The code the offending commit fixes is here: https://github.com/rust-lang/rust/commit/0a49057dd35d9bd2fcc9760a054809c30eee2a58#diff-dd0ea630ca532c2d71f4b98fc63d501f3b904f615848101d77e5713f79ae605cR1

Which I assume would break as well if we did revert :/

[camelid]

This repo seems to reproduce the issue as well -- it's from issue #78125.

Problem is, from a compiler developer standpoint, this isn't a very simple reproduction. Even if you pull out the actix-web crate, the mongodb async codebase is pretty big too.

I know, I just wanted to point it out in case it was helpful in making a smaller repro :)

[camelid]

Since this broke compilation on stable projects, and we know the culprit commit, could we revert the offending commit until this issue is resolved properly? Or is that a problem because we went stable with this commit? I feel like breaking older valid stable code is a bigger issue than breaking newer stable code.

Yes, unfortunately the PR that caused this issue was actually fixing a serious bug – it's not introducing a new feature :/

[camelid]

Reprioritizing as P-critical as discussed in the prioritization working group.

[jyn514]

If we're going to revert something, we should revert https://github.com/rust-lang/rust/pull/72796; https://github.com/rust-lang/rust/pull/75443 is just fixing a regression that earlier PR introduced. @ralfjung said in https://github.com/rust-lang/rust/issues/75313#issuecomment-673121843 that reverting the earlier PR would have other regressions, but I didn't understand - can you explain what 'not checking MIR assignments any more' means and why it's bad?

[LeSeulArtichaut]

This issue is P-critical so it will be brought up in the next compiler team meeting. The compiler team will likely have to make a choice then, but it would be best to have as much information as possible.

Also, I guess it's unlikely to have a point release for this bug, especially if it involves reverting PRs that resolved serious bugs.

[LeSeulArtichaut]

@camelid Did you remove I-compilemem on purpose? I think @jyn514 applied it according to:

For my project, I can't compile at all since my memory runs out.

[camelid]

For some reason GH let the label be applied twice. I only removed one instance of it.

[camelid]

Never mind! compilemem and compiletime blended together when I saw them. Thanks for catching that!

[lcnr]

To revert this we would have to revert #75443 as that PR caused the perf regression. That PR however is the right thing to do so I don't want to revert that, especially because there is a fairly clean way to fix this.

IMO the way forward here is to do something like #76928 for other affected code paths. I don't have a lot of time at the moment so I don't feel like I have the capacity to look into this without having a self-contained MCVE for the remaining problem.

[Davester47]

I saw this mentioned above, but this looks like it might be a good MCVE. https://github.com/rust-lang/rust/issues/75992#issuecomment-682595159. I haven't tried it though.

[jyn514]

@Davester47 that one was fixed in https://github.com/rust-lang/rust/pull/76928. There is another issue going on that doesn't yet have an MCVE: https://github.com/rust-lang/rust/issues/75992#issuecomment-703252592

[Davester47]

I see, but with rustc 1.47.0, that MCVE is hanging for me. It isn't consuming huge amounts of memory however.

[Davester47]

@jyn514 https://github.com/rust-lang/rust/pull/76928 does not fix the absurd compile times in https://github.com/rust-lang/rust/issues/75992#issuecomment-682595159. The compiler still hangs with the latest nightly, as well as stable. On 1.45.0, the memory usage steadily increases until I run out of memory, so at least that's better. I set the recursion level to the max of 29. It's memory usage remains stable except on 1.45.0, so it doesn't use all the memory on my computer like what happens on #78125.

[RalfJung]

https://github.com/rust-lang/rust/pull/72796 is a sanity check, so we don't have to run it all the time. If it is established that this check is what introduces the perf regression, we could disable it on release builds, maybe only for generators -- but then we might miss bugs.

[camelid]

Perhaps someone could run lldb on cargo build for one of the repros? I think it might help us find what's causing the hang.

Or perhaps a profiler.

[Noah-Kennedy]

I am still trying to get rid of actix and tokio-postgres from the MCVE I am currently working on. I am able to reproduce the issue on stable 1.47.0 and current nightly. It may take a while to minify this.

[jyn514]

@Noah-Kennedy thanks so much! Feel free to post a WIP if you run out of time, no need to do it all by yourself :)

[enzious]

Here's a screenshot of my compiler eating up that memory

[Davester47]

You probably already know this, but I had to find it out the hard way. Don't let rustc use up all of your memory or you will have to do a hard reset. My computer completely froze.

[Aaron1011]

A little off topic - I've found earlyoom to be extremely useful for preventing system hangs caused by running out of memory.

[Noah-Kennedy]

@jyn514 It seems like there is some specific interaction between Actix and either tokio postgres or mongo. I have stripped down much of the calltree in a patched version of tokio postgres, and I have found a specific codepath that seems to be causing the problems, at least the portion in tokio postgres. I hope to have some code that lets me get rid of tokio-postgres in the example by EOD today. I'll post a git repo with what I've currently got later as well.

[Noah-Kennedy]

On the tokio-postgres side, it looks like there is something up with the futures streams and combinators, but not confirmed yet.

[Davester47]

@Noah-Kennedy The program that I was working on until I hit this bug compiled fine until I started using a futures Stream from mongodb. There probably is something going on there.

[pnkfelix]

We've seen a couple different links to repositories in the comment thread; I spent some time reducing the repo provided by @steadylearner and have gotten it down to this:

#![allow(unreachable_code)]

use actix_web::Route;
use actix_web::http::Method;
use actix_web::HttpResponse;

pub async fn cc_create() -> HttpResponse
{
    let _new_contact = create().await; // despite lack of use, needed for repro.
    HttpResponse::Ok().json("")
}

use mongodb::bson::doc;
use mongodb::{error::Error, results::InsertOneResult, Collection};

pub async fn create() -> Result<InsertOneResult, Error> {
    let _collection: Collection = loop { };
    let r = _collection.insert_one(doc! { "email": "", "name": "" }, None);
    Ok(r.await?)  // despite unreachability, needed for repro.
}

#[actix_web::main]
async fn main() -> std::io::Result<()> {
    let _post_to = Route::new().method(Method::POST).to(cc_create); // despite lack of use, needed for repro.
    Ok(())
}

(You'll note the // despite ..., needed for repro comments above; if I remove any one of those bits of code, the slow-down goes away. presumably the .awaits are relevant, as has been hypothesized elsewhere here I think.)

(In hindsight I might have saved some time if I had instead started from the smaller (but not yet minimal, presumably) repro provided in https://github.com/rust-lang/rust/issues/75992#issuecomment-705662632 ; but in the end I assume I will end up with some similar root cause.)

My planned next step is to get rid of the dependencies on mongodb and actix_web (I just wanted to get the test case down to something small before doing so...)

(Update: By the way, the build time under 1.45.2 for the above program (on its own, with dependencies already compiled) is about 4 seconds real time, and 28 minutes under nightly a9cd294cf 2020-10-22; a slowdown factor of 420x)

[lnicola]

72796 is a sanity check, so we don't have to run it all the time. If it is established that this check is what introduces the perf regression, we could disable it on release builds, maybe only for generators -- but then we might miss bugs.

The precedent in cases like #45810 is to enable expensive sanity checks only on alt builds.

[nikomatsakis]

@pnkfelix can you verify whether #72796 and/or #75443 would fix the problem for that test?

[udoprog]

I was tinkering with kellerkindt's example, and might have found an interesting case:

use std::future::Future;

async fn a(inner: impl Future<Output = ()>) {
    inner.await
}

async fn f() {
    let f = a(async { () });
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);
    let f = a(f);

    // uncomment this and we have problems:
    // let f = a(f);
    f.await;
}

fn main() {
    let _ = f();
}

I'm on a Windows 64-bit MSVC compiler, using both nightly and master (local stage 1 build):

Without the line it takes 0.33s.
Uncommented it seemingly never finishes for me (waited about 15 minutes).

Also struggles to compile on 1.45.0, initially by hitting type length limits. And when bumped it takes an increasingly longer time to compile the more lines are added.

[nikomatsakis]

@udoprog nice reduction! I wonder if it's the same root issue. Regardless, worth exploring.

[lcnr]

the example by @udoprog is really interesting :O will look into that, even if it may not have the same underlying cause as the other regressions here it is probably related

[pftbest]

@lcnr Here is a trace for @udoprog example.
I know noting about the compiler internals but it looks to me as if 90% of the time is spent pretty-printing LayoutError.

[udoprog]

@lcnr Here is a trace for @udoprog example.
I know noting about the compiler internals but it looks to me as if 90% of the time is spent pretty-printing LayoutError.

Yeah. The hang is caused by spinning for a long time by formatting a LayoutError::SizeOverflow(..)*. Root cause simply seems to be that a really big type is generated.

*: Removing formatting for the type results in:

error: the type `...` is too big for the current architecture

error: aborting due to previous error

[lcnr]

that's probably not related to the slowdown then :sweat_smile:

Do you mind opening a new issue for that? I think we may want to fix this by somehow guarding against this in type printing

[comex]

But why would that code produce such a large future in the first place? It's not like it's multiplying the number of futures at each step; there's no obvious reason for what is presumably exponential growth in the size.

[pftbest]

Here is the trace for @pnkfelix actix_web example if that's helpful.

[jyn514]

That function is https://github.com/rust-lang/rust/blob/0a2a68edae042274fc89fdc2126bbd0b5a368131/compiler/rustc_mir/src/monomorphize/collector.rs#L339-L340

[kornelski]

In my case the build spends an hour in super_relate_tys and BoundVarReplacer (this is an inverted call tree):

[pnkfelix]

I'm guessing from @udoprog 's note that their example "Also struggles to compile on 1.45.0, initially by hitting type length limits. And when bumped it takes an increasingly longer time to compile the more lines are added" is a hint that it is not the same root cause, since the bug I believe we are addressing here is one where 1.45.0 was relatively speedy, right?

(Of course we are always interested in understanding cases where the compiler is slow, even if they are not regressions. But I would prefer those to be tracked in separate tickets from outright regression like this one.)

Update: oops, should have refreshed the page before posting; I see others have independently reached a similar conclusion.

[pnkfelix]

@pnkfelix can you verify whether #72796 and/or #75443 would fix the problem for that test?

I was hoping to reduce the problem to a single crate first, but I can work on the tack you suggest in parallel.

[pnkfelix]

@nikomatsakis

@pnkfelix can you verify whether #72796 and/or #75443 would fix the problem for that test?

I was hoping to reduce the problem to a single crate first, but I can work on the tack you suggest in parallel.

I now confirm that the compile-time regression for my test is resolved by PR #78410 (which includes a revert of PR #75443).

[Adam-Reeves]

@Noah-Kennedy The program that I was working on until I hit this bug compiled fine until I started using a futures Stream from mongodb. There probably is something going on there.

Has this been fixed? Pretty new to Rust in general but I've hit a similar issue using a futures Stream from mongodb. If I move the code into the main function it will compile, however if I move that code into a service that sits behind an actix endpoint the compile will hang seemingly indefinitely.

Update: @Davester47 FYI I just tested with the beta build and it seems to be fixed for me with mongo - hopefully it is for you too 👍

[Davester47]

@Adam-Reeves I just tested beta and it works! Nightly however still hangs, and I think that the fix missed the latest nightly. It will probably work tomorrow. Thanks everyone for helping to get this fixed.

Update: my project now builds with nightly.