JetBrains dotTrace: confusing `await` time for async function calls

Question

While profiling the app which is using async/await functionality with dotTrace I noticed that there is some inconsistency in await time for parent and children methods. Let's consider this example:

static async Task Main()
{
    await ChildMethod();
}

static async Task ChildMethod()
{
    await SomeOperationAsync();
}

The interesting thing is that await time of Main method might be (or even will be) less than the await time of the ChildMethod which looks strange to me, because intuitively await time of parent should be at least as await time of child.

For real numbers let's go back to the previous example and assume that SomeOperationAsync is Task.Delay(n). So the await time of the parent will be x (x is ~n for the app targeting .NET 6.0 and <n for the app targeting .NET Core 3.1) and the await time of child will be ~2*x.

This is the screenshot from dotTrace to get an idea how it looks (for the app targeting .NET Core 3.1 and for Task.Delay(800)):

1. This is await time of the method Main. 567ms for await ChildMethod(), I expect this to be ~800, because ChildMethod awaits Task.Delay(800)
2. This is await time of the method ChildMethod. 1140ms for await Task.Delay(800). I also expect this to be ~800.

Probably I misunderstand what await time in dotTrace is, so please correct me if so. I understand it as the time needed to schedule a task + real task execution.

Would be great if someone knew if this behavior is expected and could explain how to analyze it.

I'm using Timeline Viewer in dotTrace 2021.3.3.

UPDATE

I think I understand the first part of my confusion, namely why await time is less than time passed to Task.Delay in the Main method. This is because the timer of the task started earlier than continuation attached (internal call toAwaitUnsafeOnCompleted), therefore it awaits only for the remaining time. In my case this call takes about 300ms so that await time becomes time passed to Task.Delay - time spent on attaching continuation.

Answer 1

I think you have misunderstood the way async/await works in dotnet. You can check it in the official Microsoft docs: https://learn.microsoft.com/es-es/dotnet/csharp/language-reference/operators/await

Basically when you execute async code (a method that returns a task) the execution of that method will occur in another thread independent of the original thread, and when you need the result of that task the original thread will wait until the completion of the second thread to retrieve the result. You can read this in their docs:

The await operator doesn't block the thread that evaluates the async method. When the await operator suspends the enclosing async method, the control returns to the caller of the method.

see this example

public async Task<Person> Main()
{
    string name = await GetName(personId);
    int age = await GetAge(personId);
    return new Person(name, age)
}

public async Task<string> GetName(int personId)
{
    //imagine you have a HttpClient in this class that calls an API to get people info
    return _httpClient.GetAsync($"https://someurl.com/getName/{personId}");
}

public async Task<int> GetAge(int personId)
{
    return _httpClient.GetAsync($"https://someurl.com/getAge/{personId}");
}

this way the main execution thread will create two other threads to get the info of the age and the name of that personId, and won't stop until the moment this thread needs to retrieve some information of the other two threads (the line which returns a new Person) So what happens in your code is, as nothing uses the result of that async operation it just continues the original thread without stopping, so it's normal that the async task with the delay lasts longer than the original thread.