.NET profiling api - calculate time taken to execute async method

Question

To monitor my dotnet core application I'm using .NET clr profiling api to get method level trace and calculate the time taken by any method to complete its execution. I'm unable to get the time taken by async methods.

public ActionResult<IEnumerable<string>> Get()
    {
        Ok(RunQueryAsync().Result);
        return new string[] { "value1", "value2" };
    }
public async Task<String> RunQueryAsync()
    {
                // in the PostDataAsyncWithHeader I'm making async api request using HttpClient
                await PostDataAsyncWithHeader();
        }
        catch (Exception ex)
        {
            //display error message
            return "Exception: " + ex.Message;
        }
    }

In the above code I'm making an api request from the method PostDataAsyncWithHeader() which almost takes 5 seconds to complete. But when I use the clr profiling Enter and exit hooks to calculate the time, Get() method shows around 5 seconds but RunQueryAsync() and PostDataAsyncWithHeader() methods show 0ms. But the actual time is taken by the method PostDataAsyncWithHeader().

I want to find the exact time taken by the PostDataAsyncWithHeader() method. Please suggest me how I can achieve it.

Answer 1

The clr has no knowledge of async methods, the compiler translates them into regular methods and a state machine. As far as the runtime is concerned RunQueryAsync is a simple method that will create the state machine and call it's MoveNext method. This will run the body of the async method up until the first await that doesn't complete synchronously and then it returns with the Task object.

Your Get method on the other hand is not an async method, when it calls Task<string>.Result it blocks waiting on the task returned by RunQueryAsync to complete.

Determining when the async method completed would probably mean waiting for the MoveNext method on the state machine to return and checking that the state machine is in a 'completed' state (I usually find that the state machine is considered complete when the state is -2, but I wouldn't expect this to be contractual).