Slow MBE expansion with `async-std`

[lnicola]

use async_std::io;
use async_std::net::{TcpListener, TcpStream};
use async_std::prelude::*;
use async_std::task;

async fn process(stream: TcpStream) -> io::Result<()> {
    println!("Accepted from: {}", stream.peer_addr()?);

    let mut reader = stream.clone();
    let mut writer = stream;
    io::copy(&mut reader, &mut writer).await?;

    Ok(())
}

fn main() -> io::Result<()> {
    task::block_on(async {
        let listener = TcpListener::bind("127.0.0.1:8080").await?;
        println!("Listening on {}", listener.local_addr()?);

        let mut incoming = listener.incoming();

        while let Some(stream) = incoming.next().await {
            let stream = stream?;
            task::spawn(async {
                process(stream).await.unwrap();
            });
        }
        Ok(())
    })
}

(cargo add async-std)

17606ms - import_map_query
    17605ms - collect_import_map
        16270ms - collect_trait_assoc_items
                1ms - crate_def_map:wait (3080 calls)
              622ms - file_item_tree_query (1539 calls)
             5273ms - macro_expand (1539 calls)
             7458ms - parse_macro_expansion (2987 calls)
            0   - PerNs::filter_visibility (244 calls)
            0   - PerNs::iter_items (200 calls)
         1060ms - collect_trait_assoc_items (27 calls)
          275ms - crate_def_map:wait (1 calls)
        0   - fst_path (292 calls)

38442ms - handle_hover
    11300ms - classify_name_ref @ next
        11300ms - Semantics::analyze_impl
            11300ms - infer:wait @ main
                0   - SourceBinder::to_module_def (1 calls)
                0   - crate_def_map:wait (1 calls)
        0   - crate_def_map:wait (21 calls)
        0   - descend_into_macros (1 calls)
     5908ms - parse_macro_expansion (1532 calls)
    21234ms - ???

28820ms - handle_hover
        0   - classify_name_ref (1 calls)
        0   - crate_def_map:wait (24 calls)
        0   - descend_into_macros (1 calls)
    17672ms - parse_macro_expansion (4016 calls)
    11148ms - ???

27826ms - handle_hover
        0   - classify_name_ref (1 calls)
        0   - crate_def_map:wait (21 calls)
        0   - descend_into_macros (1 calls)
    17895ms - parse_macro_expansion (4337 calls)
     9930ms - ???

[Veykril]

async-std has received some improvements to the macro here async-rs/async-std#1005
Shall we close this?

[lnicola]

I think it's a good benchmark for our MBE expander. I think cargo check takes less than 2 seconds on async-std, so if we need 30-40 s to expand a single macro, there's probably some place for improvement.

(tested with async-std 1.10.0)

[lnicola]

One more, from analysis-stats:

                    20229ms - trait_impls_in_crate_query
                        20088ms - lang_item_query
                            20088ms - crate_lang_items_query
                                    4ms - collect_lang_item (806 calls)
                                    1ms - crate_def_map:wait (4299 calls)
                                  831ms - file_item_tree_query (2141 calls)
                                 6862ms - macro_expand (2141 calls)
                                 8518ms - parse_macro_expansion (3883 calls)
                                 3869ms - ???

The unreported time appears to be AssocItemCollector::collect_macro_items.