2

I've created a test program that runs 1000 Tasks which perform Task.Delay with a random delay between 20s and 30s. It looks like cancelling this operation takes about 10s..

Here is my test program :

class Program
{
    static async Task MainAsync()
    {
        CancellationTokenSource tokenSource = new CancellationTokenSource();

        List<Task> allTask = new List<Task>();
        Random r = new Random(9);

        async Task SafeDelay(int delay, CancellationToken token)
        {
            try
            {
                await Task.Delay(delay, token);
            }
            catch (TaskCanceledException)
            {
            }
        }

        for (int i = 0; i < 1000; i++)
        {
            var randomDelay = r.Next(20000, 30000);
            allTask.Add(SafeDelay(randomDelay, tokenSource.Token));
            ;
        }

        Stopwatch stopwatch = new Stopwatch();

        var cancelTask = Task.Delay(1000).ContinueWith(t =>
        {
            Console.Out.WriteLine("1000ms elapsed. Cancelation request start");;
            stopwatch.Start();
            tokenSource.Cancel();
        });

        await Task.WhenAll(allTask);
        await cancelTask;

        stopwatch.Stop();

        Console.WriteLine($"Cancelation done after {stopwatch.ElapsedMilliseconds} ms");
    }

    static void Main(string[] args)
    {
        Console.WriteLine("Started");
        Task.Run(MainAsync).GetAwaiter().GetResult();
        Console.WriteLine("End");
        Console.ReadLine();
    }
}

My Result with .NET Core 2.1:

Cancelation done after 9808ms

Why is cancelling Task.Delay so slow and is there a way to improve it?

My Result with .NET 4.7.1:

Cancelation done after 6200ms
Pablo Honey
  • 1,074
  • 1
  • 10
  • 23
  • 1
    @CamiloTerevinto No cancelation is requested before await Task.WhenAll(allTask) – Pablo Honey Jan 22 '19 at 13:11
  • 1
    @PanagiotisKanavos : I replace it with Task.Run(MainAsync).GetAwaiter().GetResult(); but I got the same result – Pablo Honey Jan 22 '19 at 13:12
  • @PabloHoney remove all calls to `ConfigureAwai()` for starters. Console applicaitons have no sync context. Remove `GetAwaiter().GetResult()` too. It doesn't do anything more than `.Wait()` in this case. Probably remove `Task.Run()` too as `MainAsync` is supposed to be asynchronous already – Panagiotis Kanavos Jan 22 '19 at 13:13
  • @PanagiotisKanavos : I removed all ConfigureAwait(false) but I still got 10185ms – Pablo Honey Jan 22 '19 at 13:14
  • @PabloHoney there's a lot of unusual code in this snippet. Awaiters, continuations, `ConfigureAwait`. And the way `SafeDelay` is written, you're actually counting the time taken to throw 1000 exceptions – Panagiotis Kanavos Jan 22 '19 at 13:14
  • You cannot really cancel `Task` once it is started but only prevent it actually to run, while it is scheduled. In order to cancel the `Task` you need to implement that explicitly by checking `CancellationToken`. https://stackoverflow.com/questions/48971316/when-i-use-cancelafter-the-task-is-still-running/48971668#48971668 – Johnny Jan 22 '19 at 13:17
  • @Johnny - `Task.Delay()` takes care of that. – H H Jan 22 '19 at 13:51
  • @HenkHolterman, I took a look at the source code and realize that. Tnx. – Johnny Jan 22 '19 at 14:03

2 Answers2

7

When I run this with F5 I get a similar result.
Run it with Ctrl+F5 (no debugger) and it cancels in less than 50 ms.

So you are actually timing 1000 execptions tickling the debugger. The debugger might intefere with other execution points too. Always run benchmarks in Release Mode, w/o a debugger.

H H
  • 263,252
  • 30
  • 330
  • 514
1

No repro with the question's code. Using it as is, I get :

Started
1000ms elapsed. Cancelation request start
Cancelation done after 38 ms
End

No repro with cleaned up code :

static async Task SafeDelay(int delay, CancellationToken token)
{
    try
    {
        await Task.Delay(delay, token);
    }
    catch (TaskCanceledException)
    {
    }
}


private static async Task Main()
{
    //Set 1000 ms timeout
    var tokenSource = new CancellationTokenSource(1000);
    var stopwatch = Stopwatch.StartNew();

    var allTask = new List<Task>();
    Random r = new Random(9); 


    for (var i = 0; i < 1000; i++)
    {
        var randomDelay = r.Next(20000, 30000);
        allTask.Add(SafeDelay(randomDelay, tokenSource.Token));
    }
    Console.WriteLine($"All {allTask.Count} tasks running after {stopwatch.ElapsedMilliseconds} ms");

    await Task.WhenAll(allTask);
    stopwatch.Stop();

    Console.WriteLine($"Cancelation done after {stopwatch.ElapsedMilliseconds} ms");
}

This produces :

All 1000 tasks running after 8 ms
Cancelation done after 1044 ms

The CancellationTokenSource has a 1000ms timeout.

Panagiotis Kanavos
  • 120,703
  • 13
  • 188
  • 236
  • I run it in like 10ms too. But I can't find any fundamental differences between your code and mine. – Pablo Honey Jan 22 '19 at 13:36
  • @PabloHoney *how* do you run it though? As for cleaning up, when faced with a complex problem or unexpected behaviour you *have* to remove anything unwanted. Otherwise you can't be certain whether you are measuring your test harness or the code – Panagiotis Kanavos Jan 22 '19 at 13:37
  • I run all the codes from VStudio hitting the play button (F5) – Pablo Honey Jan 22 '19 at 13:38
  • @PabloHoney the debugger catches and analyzes all exceptions, and enables a *lot* of diagnostic hooks in the code. You can't benchmark any code while debugging. – Panagiotis Kanavos Jan 22 '19 at 13:39
  • Yes but why does it does not do the same with your code above. I test it with F5 and I still got fast result like 10ms – Pablo Honey Jan 22 '19 at 13:41
  • 1
    @PabloHoney - that is not a question about the code but about the debugger. That might put threads on hold etc. A much more complicated question. Your ouriginal code was fine. – H H Jan 22 '19 at 13:47