Severe compilation time blowup in typeck_tables_of

[syntacticsugarglider]

This simple test of a codegen macro from protocol using a transport from protocol-mve-transport takes an unreasonable amount of time to compile. protocol itself takes 4 to 5 minutes to compile on my laptop but compiling this simple example takes up to 20 minutes on the same hardware, and that's with a lot of the macro expansion in protocol disabled to reduce the time spent. -Z self-profile indicates that time is overwhelmingly (> 90%) spent as self time in typeck_tables_of for this main function under collect_mod_item_types etc.

use core::fmt::{self, Display, Formatter};
use core_error::Error;
use futures::{channel::mpsc::unbounded, executor::LocalPool, task::LocalSpawnExt, StreamExt};
use protocol::protocol;
use protocol_mve_transport::{Coalesce, Unravel};
use void::Void;

#[protocol]
#[derive(Debug)]
pub struct Unit;

#[protocol]
#[derive(Debug)]
pub struct Newtype(u16);

#[protocol]
#[derive(Debug)]
pub struct Tuple(Vec<String>, u8, Newtype);

#[protocol]
#[derive(Debug)]
pub struct Test {
    data: u8,
    other: String,
    unit: Unit,
    tuple: Tuple,
}

fn main() {
    let mut pool = LocalPool::new();

    let s = pool.spawner();
    let spawner = s.clone();

    let (a_sender, a_receiver) = unbounded();
    let (b_sender, b_receiver) = unbounded();

    s.spawn_local(async move {
        Unravel::<Void, _, _, _, Test>::new(
            a_receiver.map(Ok::<Vec<u8>, Void>),
            b_sender,
            spawner,
            Test {
                data: 10,
                other: "hello".to_owned(),
                unit: Unit,
                tuple: Tuple(
                    ["there", "general", "kenoi"]
                        .iter()
                        .cloned()
                        .map(String::from)
                        .collect(),
                    5,
                    Newtype(20),
                ),
            },
        )
        .await
        .unwrap();
    })
    .unwrap();

    let spawner = s.clone();

    s.spawn_local(async move {
        let data = Coalesce::<_, _, _, _, Test>::new(
            b_receiver.map(Ok::<Vec<u8>, Void>),
            a_sender,
            spawner,
        );
        println!("{:?}", data.await.unwrap())
    })
    .unwrap();

    pool.run();
}

Unfortunately, there isn't a lot that I can do to reduce this as I have no idea what the underlying factors are that would lead to this occurring. I have a very limited understanding of incremental compilation or what individual queries are responsible for. If any logs, profile traces, etc. would be helpful please let me know and I will provide them.

[jonas-schievink]

Are you on the newest nightly?

[syntacticsugarglider]

> cargo +nightly rustc -- --version --verbose

rustc 1.44.0-nightly (1057dc97a 2020-03-20)
binary: rustc
commit-hash: 1057dc97afce39ff6a224966ece3ed438af4c1f5
commit-date: 2020-03-20
host: x86_64-apple-darwin
release: 1.44.0-nightly
LLVM version: 9.0

Let me run another profile on the latest nightly.

[syntacticsugarglider]

Same behavior on nightly 75208942f 2020-03-27. Takes less total time but the vast majority of the compilation process is still spent on that same stage and it's still longer than building the dependency that contains all of the logic by more than two times.

@jonas-schievink

[syntacticsugarglider]

I still haven't minimized this but after more investigation I found that the slowdown is mostly spent as self time in register_obligation_at, specifically in calls to contains for slices. Not sure why so many obligations are being registered but the easiest way to observe the nonlinear growth here is to change the test type in the example I initially posted to a series of nested 1-tuples around a unit, i.e. (), ((),), (((),),) and so forth. Compile times were, in my cursory testing, less than a second for the first, a few seconds for the next few iterations, thirteen seconds for the fifth, and then three minutes for the sixth. I don't have enough familiarity with the trait solver or the obligation forest data structure itself to understand why this would be happening, but annotating the elided type params of the Unravel and Coalesce in the example causes the program to compile far more expediently (i.e. in a reasonably bounded amount of time), which makes sense given that the time is spent in typeck_tables_of which I have been told is responsible for some component of inference.

[ShadowJonathan]

(after some poking around, it seems #20304 might possibly be related to this?)

Edit: As could #31849, after some more digging.

[syntacticsugarglider]

This appears to be another manifestation, like #74456, of the underlying problem tracked by #20304.