The await operator is not waiting like I expected

Question

I am working on a class DelayedExecutor that will delay the execution of an Action passed to its DelayExecute method by a certain time timeout (see code below) using the async and await statements. I also want to be able to abort the execution within the timeout interval if needed. I have written a small test to test its behavior like this:

Code for Test method:

    [TestMethod]
    public async Task DelayExecuteTest()
    {
        int timeout = 1000;
        var delayExecutor = new DelayedExecutor(timeout);
        Action func = new Action(() => Debug.WriteLine("Ran function!"));
        var sw = Stopwatch.StartNew();
        Debug.WriteLine("sw.ElapsedMilliseconds 1: " + sw.ElapsedMilliseconds);
        Task delayTask = delayExecutor.DelayExecute(func);
        await delayTask;
        Debug.WriteLine("sw.ElapsedMilliseconds 2: " + sw.ElapsedMilliseconds);
        Thread.Sleep(1000);
    }
}

The output I expected from this test was that it would show me:

sw.ElapsedMilliseconds outside DelayExecute 1: ...

Ran Action!"

sw.ElapsedMilliseconds inside DelayExecute: ...

sw.ElapsedMilliseconds outside DelayExecute 2:

However I get this and do not understand why:

sw.ElapsedMilliseconds outside DelayExecute 1: 0

sw.ElapsedMilliseconds outside DelayExecute 2: 30

Ran Action!

sw.ElapsedMilliseconds inside DelayExecute: 1015

On this blog post I read:

I like to think of “await” as an “asynchronous wait”. That is to say, the async method pauses until the awaitable is complete (so it waits), but the actual thread is not blocked (so it’s asynchronous).

This seems to be inline with my expectation, so what is going on here and where is my error?

Code for DelayedExecutor:

public class DelayedExecutor
{
    private int timeout;

    private Task currentTask;
    private CancellationToken cancellationToken;
    private CancellationTokenSource tokenSource;

    public DelayedExecutor(int timeout)
    {
        this.timeout = timeout;
        tokenSource = new CancellationTokenSource();
    }

    public void AbortCurrentTask()
    {
        if (currentTask != null)
        {
            if (!currentTask.IsCompleted)
            {
                tokenSource.Cancel();
            }
        }
    }

    public Task DelayExecute(Action func)
    {
        AbortCurrentTask();

        tokenSource = new CancellationTokenSource();
        cancellationToken = tokenSource.Token;

        return currentTask = Task.Factory.StartNew(async () =>
            {
                var sw = Stopwatch.StartNew();
                await Task.Delay(timeout, cancellationToken);
                func();
                Debug.WriteLine("sw.ElapsedMilliseconds inside DelayExecute: " + sw.ElapsedMilliseconds);
            });
    }
}

Update:

As suggested I modified this line inside my DelayExecute

return currentTask = Task.Factory.StartNew(async () =>

into

return currentTask = await Task.Factory.StartNew(async () =>

For this to work I needed to change the signature into this

public async Task<Task> DelayExecute(Action func)

so that my new definition is this:

public async Task<Task> DelayExecute(Action func)
{
    AbortCurrentTask();

    tokenSource = new CancellationTokenSource();
    cancellationToken = tokenSource.Token;

    return currentTask = await Task.Factory.StartNew(async () =>
        {
            var sw = Stopwatch.StartNew();
            await Task.Delay(timeout, cancellationToken);
            func();
            Debug.WriteLine("sw.ElapsedMilliseconds inside DelayExecute: " + sw.ElapsedMilliseconds);
        });
}

However now I have the same behavior as before. Is there some way achieve what I am trying to do using my design. Or is it fundamentally flawed?

By the way, I also tried putting await await delayTask; inside my test DelayExecuteTest, but this gives me the error

Cannot await 'void'

This is the updated test-method DelayExecuteTest, which does not compile:

public async Task DelayExecuteTest()
{
    int timeout = 1000;
    var delayExecutor = new DelayedExecutor(timeout);
    Action func = new Action(() => Debug.WriteLine("Ran Action!"));
    var sw = Stopwatch.StartNew();
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 1: " + sw.ElapsedMilliseconds);
    Task delayTask = delayExecutor.DelayExecute(func);
    await await delayTask;
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 2: " + sw.ElapsedMilliseconds);
    Thread.Sleep(1000);
}

Answer 1

After giving it some more thought I figured out, how to achieve what I was aiming for, which is to delay the start of an action and be able to abort it in case I need to. Credit goes to Lasse V. Karlsen for helping me understand the issue.

The answer by Lasse is correct for my original problem, which is why I accepted it. But in case somebody needs to achieve something similar to what I needed, here is how I solved it. I had to use a continuation task after the task started with StartNew. I also renamed the method AbortCurrentTask into AbortExecution(). The new version of my DelayedExecutor class is this:

public class DelayedExecutor
{
    private int timeout;

    private Task currentTask;
    private CancellationToken cancellationToken;
    private CancellationTokenSource tokenSource;

    public DelayedExecutor(int timeout)
    {
        this.timeout = timeout;
        tokenSource = new CancellationTokenSource();
    }

    public void AbortExecution()
    {
        if (currentTask != null)
        {
            if (!currentTask.IsCompleted)
            {
                tokenSource.Cancel();
            }
        }
    }

    public Task DelayExecute(Action func)
    {
        AbortExecution();

        tokenSource = new CancellationTokenSource();
        cancellationToken = tokenSource.Token;

        return currentTask =
            Task.Delay(timeout, cancellationToken).ContinueWith(t =>
            {
                if(!t.IsCanceled)
                {
                    var sw = Stopwatch.StartNew();
                    func();
                    Debug.WriteLine("sw.ElapsedMilliseconds inside DelayExecute: " + sw.ElapsedMilliseconds);
                }
            });
    }
}

This class now does what I expected from it. These two tests I now give the expected output:

[TestMethod]
public async Task DelayExecuteTest()
{
    int timeout = 1000;
    var delayExecutor = new DelayedExecutor(timeout);
    Action func = new Action(() => Debug.WriteLine("Ran Action!"));
    var sw = Stopwatch.StartNew();
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 1: " + sw.ElapsedMilliseconds);
    Task delayTask = delayExecutor.DelayExecute(func);
    await delayTask;
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 2: " + sw.ElapsedMilliseconds);
}

Output:

sw.ElapsedMilliseconds outside DelayExecute 1: 0

Ran Action!

sw.ElapsedMilliseconds inside DelayExecute: 3

sw.ElapsedMilliseconds outside DelayExecute 2: 1020

and

[TestMethod]
public async Task AbortDelayedExecutionTest()
{
    int timeout = 1000;
    var delayExecutor = new DelayedExecutor(timeout);
    Action func = new Action(() => Debug.WriteLine("Ran Action!"));
    var sw = Stopwatch.StartNew();
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 1: " + sw.ElapsedMilliseconds);
    Task delayTask = delayExecutor.DelayExecute(func);
    Thread.Sleep(100);
    delayExecutor.AbortExecution();
    await delayTask;
    Debug.WriteLine("sw.ElapsedMilliseconds outside DelayExecute 2: " + sw.ElapsedMilliseconds);
}

Output:

sw.ElapsedMilliseconds outside DelayExecute 1: 0

sw.ElapsedMilliseconds outside DelayExecute 2: 122

Answer 2

There's a bit going on here so I'm going to post a simple answer to begin with, let's see if it suffices.

You'we wrapped a task inside a task, this needs a double await. Otherwise you're only waiting for the inner task to reach its first return point, which will (can) be at the first await.

Let's look at your DelayExecute method in more detail. Let me begin with changing the return type of the method and we'll see how this changes our perspective. The change of return type is just a clarification. You're returning a Task that is nongeneric right now, in reality you're returning a Task<Task>.

public Task<Task> DelayExecute(Action func)
{
    AbortCurrentTask();

    tokenSource = new CancellationTokenSource();
    cancellationToken = tokenSource.Token;

    return currentTask = Task.Factory.StartNew(async () =>
        {
            var sw = Stopwatch.StartNew();
            await Task.Delay(timeout, cancellationToken);
            func();
            Debug.WriteLine("sw.ElapsedMilliseconds inside DelayExecute: " + sw.ElapsedMilliseconds);
        });
}

(note that this will not compile since currentTask is also of type Task, but this is largely irrelevant if you read the rest of the question)

OK, so what happens here?

Let's explain a simpler example first, I tested this in LINQPad:

async Task Main()
{
    Console.WriteLine("before await startnew");
    await Task.Factory.StartNew(async () =>
    {
        Console.WriteLine("before await delay");
        await Task.Delay(500);
        Console.WriteLine("after await delay");
    });
    Console.WriteLine("after await startnew");
}

When executing this I get this output:

before await startnew
before await delay
after await startnew
after await delay              -- this comes roughly half a second after previous line

So why this?

Well, your StartNew returns a Task<Task>. This is not a task that now will wait for the inner task to complete, it waits for the inner task to return, which it will (can) do at its first await.

So let's see the full execution path of this by numbering the interesting lines and then explaining the order in which things happen:

async Task Main()
{
    Console.WriteLine("before await startnew");           1
    await Task.Factory.StartNew(async () =>               2
    {
        Console.WriteLine("before await delay");          3
        await Task.Delay(500);                            4
        Console.WriteLine("after await delay");           5
    });
    Console.WriteLine("after await startnew");            6
}

1. The first Console.WriteLine executes

nothing magical here

2. We spin up a new task with Task.Factory.StartNew and await it.

Here our main method can now return, it will return a task that will continue once the inner task has completed.

The job of the inner task is not to execute all the code in that delegate. The job of the inner task is to produce yet another task.

This is important!

3. The inner task now starts executing

It will essentially execute all the code in the delegate up to and including the call to Task.Delay, which returns a Task.

4. The inner task arrives at its first await

Since this will not already have completed (it will only complete roughly 500ms later), this delegate now returns.

Basically, the await <this task we got from Task.Delay> statement will create a continuation and then return.

This is important!

6. Our outer task now continues

Since the inner task returned, the outer task can now continue. The result of calling await Task.Factory.StartNew is yet another task but this task is just left to fend for itself.

5. The inner task, continues roughly 500ms later

This is now after the outer task has already continued, potentially finished executing.

---

So in conclusion your code executes "as expected", just not the way you expected.

There are several ways to fix this code, I'm simply going to rewrite your DelayExecute method to the simplest way to do what you want to do:

Change this line:

    return currentTask = Task.Factory.StartNew(async () =>

Into this:

    return currentTask = await Task.Factory.StartNew(async () =>

This will let the inner task start your stopwatch and reach the first await before returning all the way out of DelayExecute.

The similar fix to my LINQPad example above would be to simply change this line:

await Task.Factory.StartNew(async () =>

To this:

await await Task.Factory.StartNew(async () =>