{"id":6111,"date":"2015-12-29T10:33:00","date_gmt":"2015-12-29T10:33:00","guid":{"rendered":"https:\/\/blogs.msdn.microsoft.com\/webdev\/2015\/12\/29\/using-asp-net-module-to-debug-async-calls\/"},"modified":"2023-09-21T11:36:33","modified_gmt":"2023-09-21T18:36:33","slug":"using-asp-net-module-to-debug-async-calls","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/dotnet\/using-asp-net-module-to-debug-async-calls\/","title":{"rendered":"Using ASP.Net Module to Debug Async Calls"},"content":{"rendered":"

I had a web application that generously used async\/await keywords. The application encountered a slow response possibly due to a pending backend database call. I attached a debugger to the application. There was, however, nothing running\u00a0in the process (see Figure 1), which was expected due to the calls being async and the waiting threads were no longer active.<\/p>\n

It is frustrating seeing no code running when debugging applications using asynchronous methods. What can I do?<\/p>\n

\n \"\"<\/a>\n<\/p>\n

\n Figure 1 \u201cNothing\u201d is running in the process. The ‘Location’ column is empty.\n<\/p>\n

Introducing TPLEventListenerModule<\/strong><\/h3>\n

Andrew Stasyuk has a good post (https:\/\/msdn.microsoft.com\/en-us\/magazine\/JJ891052.aspx<\/a>) introducing a way to get the call stacks (or causality chains) of async tasks. I figured I could leverage this method in my web application.<\/p>\n

In a nutshell, the .NET Framework defines an event source, TplEtwProvider<\/a>, which fires events that allow you to track Task lifetime. In .NET 4.5 and above, it is possible to subscribe to the event source to get the events. Here is what I do. I create an ASP.Net HttpModule, TPLEventListenerModule, which contains an event listener listening to TPL (Task Parallel Library) events.\u00a0The listener captures two kinds of TPL event, TaskWaitBegin and TaskWaitEnd. Upon capturing an event, the listener stores the Task\u2019s information — such as, the Id of the task, the StackTrace where the event happens, the created time of the event, the type of the event, and so on — in memory. The module ensures the listener initialized\u00a0during BeginRequest event of\u00a0requests. And I create an HttpHandler for viewing the stored information. The task information can also be accessed via APIs or be found in a dump of the web application.<\/p>\n

The\u00a0solution of the module\u00a0is attached to this blog post. Here are some more details about the module.<\/p>\n

\u00a0 \u00a01. The module is an ASP.Net HttpModule. To use it I just need to register the module in my web application\u2019s web.config. The section to be added in web.config looks like this,\u00a0<\/p>\n

<system.webServer> \r\n    … \r\n    <modules>\r\n      <add name=\"TPLEventListenerModule\" type=\"TaskEventListenerModule.TPLEventListenerModule, TaskEventListenerModule\"\/>\r\n    <\/modules>\r\n    …\r\n  <\/system.webServer><\/pre>\n
\u00a0 \u00a02. The captured event info is stored in the following two ways:\u00a0<\/p>\n
\u00a0\u00a0\u00a0Each HttpContext instance has a SingleRequestTaskStore instance that stores the current active Task\u2019s info for the corresponding request.<\/p>\n
\n  \"\"<\/a>\n<\/p>\n
\n  Figure 2 A SingleRequestTaskStore instance is stored in the HttpContext’s Items bag.\n<\/p>\n
\u00a0\u00a0\u00a0Each HttpContext instance has a DebuggingInfoList containing all events for the corresponding request. \u00a0<\/p>\n
\n  \"\"<\/a>\u00a0\n<\/p>\n
\n  Figure 3 A DebuggingInfoList contains all Task Begin\/End events for the corresponding request.\n<\/p>\n
\u00a0 \u00a03. The module puts\/removes every request\u2019s HttpContext into\/from a ConcurrentItemStore in the request\u2019s BeginRequest\/EndRequest event. I can access the stored HttpContext via the CurrentContextViewer.\u00a0<\/p>\n
\"\"<\/a><\/p>\n
\n  Figure 4 The Contexts property contains HttpContexts for all active requests.\n<\/p>\n
\u00a0 \u00a04. I wrote an HttpHandler, ViewAsyncTaskInfoHandler. The handler can give me a view of all active requests and all async Task info if there is any. To enable the handler in my application, in web.config I added a section like this,<\/p>\n
<system.webServer>\r\n    …\r\n    <handlers>\r\n      <add type=\"TaskEventListenerModule.ViewAsyncTaskInfoHandler, TaskEventListenerModule\" name=\"ViewAsyncTaskInfoHandler\"\r\n           resourceType=\"Unspecified\" path=\"vat.axd\" verb=\"POST,GET,HEAD\"><\/add>\r\n    <\/handlers>\r\n    …<\/pre>\n
Trying it Out<\/h3>\n
The attached solution includes \u00a0a demo project. The default page has two hyperlinks, \u201cAsync Page\u201d and \u201cView Async Tasks\u201d. Start the application and browse the default page, you can try clicking \u201cAsync Page\u201d a few times and then click \u201cView Async Tasks\u201d, and\u00a0\u201cView Async Tasks\u201d page\u00a0will show you\u00a0a list of requests running async tasks.<\/p>\n
With the TPLEventListenerModule in place, I can now know what async task my request is awaiting even though I do not see any active thread. If you ever have the same problem, get a copy of the module into your project today.<\/p>\n
\u00a0<\/p>\n
TaskEventListenerModule.zip<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"
I had a web application that generously used async\/await keywords. The application encountered a slow response possibly due to a pending backend database call. I attached a debugger to the application. There was, however, nothing running\u00a0in the process (see Figure 1), which was expected due to the calls being async and the waiting threads were […]<\/p>\n","protected":false},"author":465,"featured_media":58792,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[197],"tags":[],"class_list":["post-6111","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-aspnet"],"acf":[],"blog_post_summary":"
I had a web application that generously used async\/await keywords. The application encountered a slow response possibly due to a pending backend database call. I attached a debugger to the application. There was, however, nothing running\u00a0in the process (see Figure 1), which was expected due to the calls being async and the waiting threads were […]<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/posts\/6111","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/users\/465"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/comments?post=6111"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/posts\/6111\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/media\/58792"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/media?parent=6111"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/categories?post=6111"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/dotnet\/wp-json\/wp\/v2\/tags?post=6111"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}