DotTrace系列：8. 时间诊断之 异步代码 和 Task任务

一：背景

1. 讲故事

现如今的很多代码都是awaitasync+Task的方式，对它们进行性能洞察非常有必要，awaitasync 本质上就是将状态机塞入到 Task 的 m_continuationObject 延续字段上，和 ContinueWith 没有本质区别，这一篇我们就来聊一聊。
二：异步和Task

1. 诊断异步代码时间

这里我就用异步读取 1G文件内容 来举例，参考代码如下：

1. class Program
2. {
3.     static async Task Main()
4.     {
5.         // 创建并启动Stopwatch
6.         Stopwatch stopwatch = new Stopwatch();
7.         stopwatch.Start();
9.         string filePath = @"D:\1GB_LogFile.log";
10.         await DoRequest(filePath);
12.         // 停止并显示总耗时
13.         stopwatch.Stop();
14.         Console.WriteLine($"总耗时: {stopwatch.Elapsed.TotalSeconds:F2}秒");
15.         Console.ReadLine();
16.     }
18.     static async Task DoRequest(string filePath)
19.     {
20.         CheckParameter();
22.         const int chunkSize = 512 * 1024 * 1024; // 每次读取512MB
24.         try
25.         {
26.             Console.WriteLine("开始分块读取文件...");
27.             int chunkCount = 0;
28.             long totalBytesRead = 0;
30.             using (var fileStream = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read, 4096, FileOptions.Asynchronous))
31.             {
32.                 byte[] buffer = new byte[chunkSize];
33.                 int bytesRead;
35.                 while ((bytesRead = await fileStream.ReadAsync(buffer, 0, buffer.Length)) > 0)
36.                 {
37.                     totalBytesRead += bytesRead;
38.                     chunkCount++;
40.                     // 处理当前块的数据
41.                     string chunkContent = Encoding.UTF8.GetString(buffer, 0, bytesRead);
42.                     Console.WriteLine($"读取块 {chunkCount}, 大小: {bytesRead / 1024}KB, 总计: {totalBytesRead / 1024 / 1024}MB");
43.                 }
44.             }
46.             Console.WriteLine($"文件读取完成，共 {chunkCount} 块");
48.             await Task.CompletedTask;
49.         }
50.         catch (Exception ex)
51.         {
52.             Console.WriteLine($"出错: {ex.Message}");
53.         }
54.     }
56.     static void CheckParameter()
57.     {
58.         Console.WriteLine("检查参数开始...");
59.         Thread.Sleep(5000);
60.         Console.WriteLine("检查参数结束...");
61.     }
62. }

复制代码

使用 dotrace 的 timeline 模式对程序进行跟踪，可以看到异步方法耗时 6.25s，截图如下：

接下来的问题是这 6.25s 是怎么消耗掉的呢？可以用 F5 搜索 DoRequest 方法的耗时，截图如下：

从图中可以清楚的看到如下信息：

• CheckParameter: 耗时 5000ms
  
• continuations: 即 Task.m_continuationObject 字段中的任务，这是委托到其他线程的执行时间。
  
• other: 有 Stream.ReadAsync，JIT 动态编译等等，其实就是底层状态机的部分代码块，参考如下：
  

如何想观察这 967ms 是如何消耗掉的，可以展开一下，这里要注意一点，这里的深灰色展示的，截图如下：

是不是挺有意思的。
2. 诊断Task代码时间

除了异步代码会横跨多个线程，其实 Task 也有同样的场景，接下来将刚才的异步代码改成 Task模式，核心代码如下：

1. static Task DoRequest(string filePath)
2. {
3.     CheckParameter();
5.     const int chunkSize = 512 * 1024 * 1024; // 每次读取512MB
7.     return Task.Run(() =>
8.     {
9.         try
10.         {
11.             Console.WriteLine("开始分块读取文件...");
12.             int chunkCount = 0;
13.             long totalBytesRead = 0;
15.             using (var fileStream = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read, 4096, FileOptions.Asynchronous))
16.             {
17.                 byte[] buffer = new byte[chunkSize];
18.                 int bytesRead;
20.                 while ((bytesRead = fileStream.Read(buffer, 0, buffer.Length)) > 0)
21.                 {
22.                     totalBytesRead += bytesRead;
23.                     chunkCount++;
25.                     // 处理当前块的数据
26.                     string chunkContent = Encoding.UTF8.GetString(buffer, 0, bytesRead);
27.                     Console.WriteLine($"读取块 {chunkCount}, 大小: {bytesRead / 1024}KB, 总计: {totalBytesRead / 1024 / 1024}MB");
28.                 }
29.             }
31.             Console.WriteLine($"文件读取完成，共 {chunkCount} 块");
32.         }
33.         catch (Exception ex)
34.         {
35.             Console.WriteLine($"出错: {ex.Message}");
36.         }
37.     });
38. }

复制代码

使用 dottrace 的 timeline 模式跟踪，拿到跟踪文件之后，使用 F5 搜索 DoRequest 方法，截图如下：

从卦中可以看到 DoRequest 方法消耗了 5010ms，根据调用栈发现没有统计到 Task scheduled -> Program+c__DisplayClass1_0.b__0() 的耗时，这个就有点无语了，不像异步代码有 +Continuation 复选框。。。可以归到Total Time 上，这一点就比较遗憾了。
再说一个比较好的地方，dottrace 专门提供了一个 Task 复选框，它可以观测到追踪时间内程序生成了多少个Task，以及 Task 的执行时间，截图如下：

从卦中的 时间轴 来看，尼玛，Task 怎么跑到 Garbage Collection 线程上执行，这线程是专门用来执行后台GC的，很明显这是有问题的。。。所以也不要太相信 dotTrace 哈。
三：总结

对 异步 和 Task 的下钻分析，非常有利于解决类似线程饥饿，Task阻塞等问题，希望本篇能给大家带来一点帮助。

作为JetBrains社区内容合作者，如有购买jetbrains的产品，可以用我的折扣码 HUANGXINCHENG，有25%的内部优惠哦。

来源：程序园用户自行投稿发布，如果侵权，请联系站长删除
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！