Tracing Threads In Async Pages

Let’s look at the impact of the Async=”true” attribute in an @ Page directive for a web form using RegisterAsyncTask. Refer to the 2nd chunk of source code from last week’s “Async pages” post.

The new tracepoint feature in VS 2005 makes analyzing thread behavior in this scenario quite easy. Tracepoints are set like breakpoints, but instead of halting execution you can ask a tracepoint to log a message to the debug output window. It’s like having calls to Trace.WriteLine in your code.

I set tracepoints at the beginning of Page_Load, Page_Unload, and in each of the begin and end delegates for the async tasks. The tracepoints log the Thread ID and their location. When the async tasks are set to execute in parallel, and the Async=”true” attribute is set in the @ Page directive, we see the following trace output:

Thread: 0xA54 Page_Load
Thread: 0xA54 Task 1 Start Delegate
Thread: 0xA54 Task2 Start Delegate
Thread: 0x9B4 Task1 EndDelegate
Thread: 0xA68 Task2 EndDelegate
Thread: 0xA68 in Unload, Elapsed time = 5.0s

The original thread (0xA54) is the thread selected to start processing the request, but once she has kicked off the async tasks she goes back to the thread pool to service other requests. Thread 0xA68 finishes the last async web service call and goes on to finish the page processing in Page_Unload.

Thread 0xA54 is from the worker thread threadpool. Threads 0x9B4 and 0xA68 are from the completion port thread pool. This is the behavior Fritz Onion refers to in a comment on my previous post. We can verify this behavior using SOS from the VS.NET debugger’s immediate window (output modified to fit on the screen):

.load sos
extension C:\WINDOWS\Microsoft.NET\Framework\v2.0.50215\sos.dll loaded
 
!threads
ThreadCount: 10
UnstartedThread: 0
BackgroundThread: 10
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
     
OSID APT 
 9bc Ukn (Threadpool Worker)
 9c4 MTA (Finalizer)
 9c8 MTA (Threadpool Completion Port)
 9cc Ukn
 9b4 MTA (Threadpool Completion Port)
 a28 MTA (Threadpool Worker)
 a3c MTA
 a54 MTA (Threadpool Worker)
 a68 MTA (Threadpool Completion Port)
 a80 MTA (Threadpool Completion Port)

Now we will set Async=”false” in the @ Page directive, and restart.

Thread: 0xC54 Page_Load 
Thread: 0xC54 Task1 Start Delegate 
Thread: 0xC54 Task2 Start Delegate 
Thread: 0xC6C Task1 EndDelegate 
Thread: 0xC80 Task2 EndDelegate 
Thread: 0xC54 in Unload, Elapsed time = 5.0s 

Threads 0xC6C and 0xC80 are from the completion port threadpool, but notice thread 0xC54 has to wait around and finish the page processing. This reduces scalability and would be similar to the processing that happens in first code sample of the previous post.

Moral Of The Story

Always remember to set Async=”true” in the @ Page directive if you use RegisterAsyncTask.