dotTrace
 
Get dotTrace

Analyze Async Calls

Last modified: 26 May 2024

One of the downsides of asynchronous code is it's tough to profile it and analyze its performance. This is because when an asynchronous method is executed, the control is switched to a different thread and back, tangling the resulting call tree.

dotTrace significantly simplifies the analysis of asynchronous code: It marks all async call nodes in Call Tree and groups the corresponding await time and continuation code under that node. This means that you can quickly find all "parts" of an asynchronous call in one place instead of searching for them in different call stacks.

To better understand how dotTrace treats asynchronous code, consider the following example (the code is shown on the left, the corresponding Call Tree on the right):

Async calls analysis

As you can see, all "parts" of the asynchronous call are shown inside the async RunAsyncOperation node:

  • The total time of RunAsyncOperation is calculated as

    119 ms = Init() 101 ms + ReadAsync() 13 ms + clr.dll 3.7 ms + FileStream.ctor() 0.6 ms

  • The Init method (101 ms) is executed on the Main thread, therefore, its time is added to the total time of RunAsyncOperation.

  • The ReadAsync is started on the Main thread (13 ms), but the subsequent task is run on a thread pool. Thus, the time of the Task execution node (819 ms) is shown grey and is not added to the total time of RunAsyncOperation.

    Async calls task execution
  • The await time in our case is equal to the Task execution time (819 ms), but in real life, it can be higher as it also includes the time the task waits in the schedule.

  • The continuations node is a continuation code which in our case consists of a single ProcessFile method (301 ms). As this call is executed on the thread pool, its time is also shown gray and is not added to the total time of RunAsyncOperation.