In my last post I introduced the async and await keywords and I showed you what the C# compiler generates from an async method.
In this post we will see what the PurePath looks like when we use an async API in our code. Feel free to follow my steps by downloading the free trial of Dynatrace. I also shared the PurePath on our Share Your PurePath page for you to download and explore.
Recap from the last post
As we have seen every async method is turned into a struct with a MoveNext() method. This method is called every time when the state machine changes its state. On the C# level “changing the state” means that the await operation returns the result of an asynchronous call.
The sample application
Now let’s create a small application which uses the async/await keywords:
We have here 2 async methods namely StartRequestAsync and GetHttpResponseAsync. As we learned before from these two methods the compiler generates two state machines.
Let’s analyze this in Dynatrace
When we add a Dynatrace agent to this application and open the Class Browser under Sensors in the System Profile we immediately see the two new structs (Program+<GetHttpResponse>d__3 and Program+<StartRequest>d__0). These structs are already instrumented by the thread tagging sensor, so if you enabled the thread tagging sensor (on by default) you don’t have to place anything into these structs. Of course the normal methods are also visible and if you want to see them in a PurePath then you have to place a sensor for these methods like for any other methods. We only instrument the state machines automatically so if you select an async method we can track every MoveNext() started by the selected method.
First let’s see the transaction flow of this code:
As you may expect, there is nothing new here. Our Agent sends a request to wikipedia.org and that’s it. The only place where we see changes caused by the new pattern is the PurePath.
In Dynatrace we always show what really happens on the CLR. We discussed at length if it would make sense in this case to show something more related to the original code and virtually undo what the compiler did with the async methods. Our decision was to stick with the “show what really happens” principle.
So now with this in mind let’s examine this PurePath:
On the top we see that the main method is called and from there we call the StartRequestAsync() method. Remember from the last post: the body of every async method becomes a skeleton code which initializes the state machine (in this case the Program+<StartRequestAsync>d_0) and starts it so we end up in the MoveNext method. This is exactly what we see in the third line.
This calls our GetHttpReponseAsync() method, which is an async method again. And here comes the cool stuff. We have two branches from this method caused by the await keyword and the underlying API which creates a new thread.
Look at the ThreadName and the Elapsed Times columns! We step into the GetHttpResponseAsync() at 50.91 on thread 1. From here the next method call is at 53.97 below the complete asynchronous invocation block. There we call the MoveNext method of the Program+<GetHttpReponseAsync>d_3 the first time (we are still on thread 1, because both state machines are still in the initial state before the first await keyword) and here we hit the HttpClient class which send the request to Wikipedia.org, but this happens already on a different thread, because the HttpClient class automatically created a new thread.
Here I would like to point out that at 1127.17 thread1 says “goodbye” to our tiny application, since we never see it again after this line. And all this is done by the framework, so you don’t have to take care of this. In a console application like this it is not a big deal, but if this would be a web application which uses a threadpool then at this point we already had a free thread to do other useful work.
If you follow this path you see classes like Task, HttpWebRequest and at 1291.59 our branch ends. This is the point where Thread 4 sends the Http request.
After we have the response (this is at 1711.28) the MoveNext method of the Program+<GetHttpResponseAsync>d_3 struct is called again, but this time the method “wakes up” on thread 10. Remember from the last post: this is possible because the generated code passes the state machine as a parameter for the asynchronous call. Since the GetHttpResponseAsync method is done it calls the MoveNext() of the Program+<StartRequestAsync>d_0, so we end up in this method the second time, but we are now after the await keyword. As you see in the original code at the end of this method we call NormalMethod which we see at 1834.01 in the PurePath and with this we are at the end of our program.
The takeaway from this post is that if you use the async/await keywords and you want to understand which part of the original method was called at which point you should look at the Elapsed Time and Thread Name columns. Every time the MoveNext method is called it means that an asynchronous operation awaited by the await keyword is finished. If you want to know from which method the MoveNext method is called (because realistically you will have more than one async method) you always should look at the Class column.