console freezes in CONNECTING state when there are too many tasks

[hatoo]

console freezes in CONNECTING state to this application.

use std::time::Duration;

#[tokio::main]
async fn main() -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
    console_subscriber::init();

    let futures = (0..10/* A smaller number like 5 was Ok */)
        .map(|_| {
            tokio::spawn(async {
                loop {
                    tokio::time::sleep(Duration::from_millis(
                        10, /* A larger number like 1000 was Ok */
                    ))
                    .await;
                }
            })
        })
        .collect::<Vec<_>>();

    for f in futures {
        f.await?;
    }

    Ok(())
}

As commented above, it's Ok if the number of spawned futures is small or sleep duration is large.

[Freax13]

This is caused by a deadlock:

1. Spawning many tasks and Sleeps causes a lot of events.
2. The capacity of TasksLayers::tx drops under TasksLayers::flush_under_capacity.
3. Flush::trigger is called, the triggered flag is set and the aggregator is notified.
4. The aggregator picks up the notification and clears the triggered flag.
5. The aggregator processes some but not all events because tokio's mpsc implementation yields after the tasks budget has been used up even if there still are items left in the channel. This is usually fine but .now_or_never() is called on the future, so only the future is canceled and the task doesn't yield.
6. The aggregator waits for the next notification and polls Notified which has no notification, so it locks a mutex and tries to clone the tasks waker to put it on its list of wakers.
7. Cloning the waker causes another event.
8. This event is put on the channel.
9. Because the channel is still mostly full and the triggered flag is not set, Flush::trigger called once again.
10. Notifier::notify_one tries to lock the mutex locked in step 6. and a deadlock occurs.

This happens so quickly because the channel might not be fully drained, but even if it was, Notified cloning the waker could still be the one event pushing it above the limit (although that is much less likely).

One way to deal with this might be to suppress sending the notification by setting a flag when the Notified future is polled.

[seanmonstar]

It seems this is another case of using instrumented synchronization primitives inside the layer trying to react to the instrumentation causing unhappy times.

[hatoo]

It seems that the console doesn't freeze for the example now.

[pnkfelix]

thanks @hatoo !

closing as fixed then. (I'm not sure if it was fixed by PR tokio-rs/tokio#4129, or by something else that happened in the meantime, but I don't think we are going to attempt to track down the exact cause of the fix.)