DotTrace系列：4. 诊断窗体程序变卡之原因分析
一：背景1. 讲故事
写这一篇是因为昨天看 dottrace 官方文档时，在评论区看到了一条不友好的评论，截图如下：
虽然语气上带有些许愤怒，但说实话人家也不是无中生有，作为 dottrace 的忠实粉丝我还是能够理解他的心情的，所以这篇我用最新的 2025.01 版 dottrace 来演示一下，时过境迁有些功能和性能基准虽然已经不一样了。
话不多说我们开始吧。
二：程序变卡分析
1. 现象描述
案例代码是一个窗体程序，它可以将上传文件的内容按行反转，比如说 abcd -> dcba，我准备了一个 1G 的日志文件，在程序运行过程中我发现程序特别吃内存，而且在处理过程中明显发现程序卡卡的，能否帮我分析下到底怎么回事，案例代码可下载：https://github.com/DarthWeirdo/dotTrace_Timeline_Get_Started
上面的项目下载好之后，一定要改成 x64 位的，运行之后截图如下：
因果论中的 果，现在我们知道了，接下来就是由果推因，那怎么推呢？使用 dotTrace 哈。
2. dotTrace 分析
使用 timeline 模式对 MassFileProcessing 程序进行性能数据收集，最后的性能图表如下：
这里面有几个概念要解释：
[*]UI Freeze
简而言之就是如果 UI 超过 200ms 都不响应用户，就属于 Freeze，可能有些朋友比较懵，上一段代码参考如下：
int APIENTRY wWinMain(_In_ HINSTANCE hInstance,
_In_opt_ HINSTANCE hPrevInstance,
_In_ LPWSTR lpCmdLine,
_In_ int nCmdShow)
{
MSG msg;
// Main message loop:
while (GetMessage(&msg, nullptr, 0, 0))
{
if (!TranslateAccelerator(msg.hwnd, hAccelTable, &msg))
{
TranslateMessage(&msg);
DispatchMessage(&msg);
}
}
return (int) msg.wParam;
}这里的 Freeze 原因有很多，常见的有如下三种：
[*]由于queue队列积压，导致用户投送过来的消息，GetMessage 在 200ms 内无法及时取到。
[*]由于用户投送过来的是长耗时任务，导致 DispatchMessage 在 200ms 内无法处理完。
[*]由于gc触发，导致 UI 被 Suspend >200 ms。
再回头观察上面的面板，可以看到冻结时间高达 UI Freeze =11.4s。
[*]子模块条状时间分布
从条状图上可以看到，11s 的时间主要被 GCWait 和 WPF 这块吃掉了，前者占比50%，后者占比43%，接下来稍微解释下这两个词的概念:
[*]GCWait 当前线程等待其他线程GC操作完成而处于的一种等待状态，比如下面的截图：
[*]WPF UI处理相关的业务逻辑，比如UI更新等等。
接下来我们就要逐个分析这两块了。
3. 为什么GC Wait 高达 50%
观察 Main 时间轴上可以看到有很多间断的 灰色区域，这些灰色区域即是所谓的暂停(GC wait)，截图如下：
根据CLR的相关知识，只有两种原因会导致 GC Wait 产生。
[*]完整的 blocking GC，即著名的 STW 机制。
[*]background gc 三阶段中的 blocking 阶段，这块我的训练营里说的很细。
有了这个思路，接下来就是观察到底是哪个线程触发的，在 Visible Threads 中按需选择线程，这里我就勾上 CLR Worker和 Garbage Collection 线程，这里稍微提一下，2025版的 dottrace 新增了多tab页模式，这个太方便了，现在我可以多tab分析了，因为我用windbg 的时候也是这么玩的，非常利于分析加速，截图如下：
https://img2024.cnblogs.com/blog/214741/202506/214741-20250625121918997-218498979.png
Gargage Collection 和 CLR Worker 都出来后，缩小时间轴，宏观的观测下Main灰色和其他线程的深蓝色，截图如下：
从卦中可以清晰的看到很多的Main阻塞看起来是 CLR Worker 触发GC导致的，那是不是的呢？观察一下便知哈，将时间轴稍微调整下，选择 Flame Graph 火焰图，从中就有 plan_phase，这是GC三阶段中经典的 计划阶段，截图如下：
接下来就要思考了，为什么会触发那么多次GC，这些GC是大GC还是小GC呢？要调查这个原因，可以单独勾选 CLR Worker 线程，可以看到如下信息：阻塞式GC高达 92.7% 同时 1代GC 高达 71.7%，截图如下：
根据dump分析经验，看样子 UI 卡卡的和过频的GC有关。GC触发本质是要到gc堆上捞垃圾，所以肯定有人在不断的丢垃圾，所以从这个角度继续突破，选择 .NET Memory Allocation 事件，然后观察 hotspots 区域，可以看到 总计 12G 的内存分配，Reverse方法就独吞 4.9G，说明还是非常吃内存的，截图如下：
点击源代码观察，参考如下：
internal class StringReverser
{
private readonly string _original;
public StringReverser(string original)
{
_original = original;
}
public string Reverse()
{
char[] charArray = _original.ToCharArray();
Array.Reverse(charArray);
return new string(charArray);
}
}从卦中可以看到这块会产生很多的临时 char[] 和 string 对象，在1G日志的加持下导致GC频繁触发，在后续版本优化中这块是一个非常重要的点，可能你需要用 ArrayPool 或者 Span 等机制来减少临时对象的过多产生。
4. 为什么 WPF 高达 42%
WPF占比过高其实也意味着更新UI的操作比较频繁，这种情况也会导致程序在响应UI方面会有所延迟，那到底是谁在频繁的更新 UI呢？
可以勾选上 Running , WPF 等选项，然后观察 火焰图，截图如下：
从卦中的火焰图中的 Dispatcher.ProcessQueue() 方法可以判断当前真的是频繁的更新UI，因为WPF在忙碌的处理队列，而它的发起者正是 ProcessInProgress 方法，观察方法的源码，参考如下：
private void ProcessInProgress(object sender, ProgressChangedEventArgs e)
{
var upd = (ProgressUpdater)e.UserState;
lblProgress.Content = $"File {upd.CurrentFileNmb} of {upd.TotalFiles}: {e.ProgressPercentage}%";
}
private void ProcessFiles(object sender, DoWorkEventArgs evts)
{
try
{
_updater.TotalFiles = FilePaths.Count;
for (var i = 0; i < FilePaths.Count; i++)
{
EmKeyPress();
_updater.CurrentFileNmb = i + 1;
var path = FilePaths;
_lines = File.ReadAllLines(path);
for (var j = 0; j < _lines.Length; j++)
{
var line = _lines;
var stringReverser = new StringReverser(line);
_lines = stringReverser.Reverse();
if (j % 5 == 0)
{
var p = (float)(j + 1) / _lines.Length * 100;
Worker.ReportProgress((int)p, _updater);
}
}
File.WriteAllLines(path, _lines);
}
}
catch (Exception e)
{
MessageBox.Show(e.ToString());
}
}从卦中代码可以看到，原来 if (j % 5 == 0) 就会通过 Worker.ReportProgress((int)p, _updater); 报告进度进而触发 ProcessInProgress 方法。
找到问题之后，优化就相对简单了，将 if (j % 5 == 0) 5 改成更大一些即可，比如 1000，5000。
三：总结
用 dottrace 分析这类程序变慢的问题，真的再适合不过，这篇文章主要还是对那个不友好评论的回应和修正吧。
作为JetBrains社区内容合作者，如有购买jetbrains的产品，可以用我的折扣码 HUANGXINCHENG，有25%的内部优惠哦。
来源：程序园用户自行投稿发布，如果侵权，请联系站长删除
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！
页:
[1]