dotTrace 2025.2 Help

查找 UI 卡顿的原因

在本教程中,我们将详细了解关键的分析步骤,并向您介绍 dotTrace Viewer 用户界面。 我们还将分析一个示例应用程序,并尝试确定其 UI 卡顿的原因,这是一个非常常见的分析任务。

示例应用程序

我们的示例应用程序用于反转文本文件中的行,例如, ABC => CBA。 通过 选择文件 按钮,用户可以选择一个或多个要处理的文本文件。 处理文件 按钮运行一个单独的 BackgroundWorker 线程,该线程反转文件中的行。 进度显示在窗口的左下角。 处理完成后,标签会报告 所有文件均已成功处理

源代码可在 github 上获取。

t1_app.png

该应用程序存在一个严重缺陷。 开始文件处理后,用户会遇到 UI 卡顿,直到处理完成。

让我们使用时间线分析来找出这些卡顿发生的原因!*

运行分析器并获取快照

  1. 在 Visual Studio 中打开 MassFileProcessing.sln 解决方案。

  2. 通过选择 ReSharper | Profile | Run Startup Configuration Performance Profiling... 运行分析器。

  3. 分析类型 中,选择 时间线

    t1_profiling_options.png
  4. 点击 运行。 dotTrace 将运行我们的应用程序,并显示一个用于控制分析过程的特殊控制器窗口。

    t1_profiling_controller.png

    现在,让我们尝试在应用程序中重现性能问题。

  5. 点击 选择文件 并选择应用程序附带的 Text Files 文件夹中的五个文本文件。

    t1_app.png
  6. 点击 处理文件 开始文件处理。 如您所见,应用程序非常卡顿。 实际上,您甚至无法看到文件处理的进度,直到处理完成并显示 所有文件已成功处理消息

  7. 通过在控制器窗口中点击 获取快照并等待 收集时间线分析快照。 快照将在 Visual Studio 中的单独 性能分析器 工具窗口中打开。

  8. 关闭应用程序。 这也会关闭控制器窗口。

分析时间线分析快照

  1. 点击 线程 打开 线程 工具窗口。 默认情况下,它显示所有应用程序线程,不包括非托管线程。* 请注意,您看到的所有过滤器值都是为当前可见的线程计算的。 对于进一步的分析,我们对不执行任何工作的线程不感兴趣。 因此,首先让我们去掉它们。

    t1_threads.png
  2. 查看工具窗口中的线程列表。 它包含 主要 应用程序线程、运行时用于完成对象的 终结器 线程(在我们的应用程序中不执行任何工作)以及 垃圾收集 线程(用于执行后台 GC)。 处理我们应用程序中文件的 BackgroundWorker 线程被标识为 线程池 (ID 13456),因为后台线程是由 CLR 线程池创建的。 还有一个 线程池 (ID 7416),它不执行任何工作。 这可能是某个辅助 CLR 线程池。 让我们隐藏 终结器线程池 (ID 7416)线程,因为它们与我们的分析无关。

  3. 线程 工具窗口中选择 终结器线程池 (ID 7416)线程。

  4. 右键点击并选择 隐藏选定的线程

    t1_hide_threads.png
  5. 查看 线程 窗口。 当前应用于快照数据的过滤器为: "选择所有线程的生命周期区间,隐藏的除外"

    t1_hidden_threads.png

    注意其他过滤器中的数据是如何受到影响的。 例如, 线程状态 中的状态时间现在是为所有线程(隐藏的除外)计算的。 热点调用树 也发生了变化,仅显示来自过滤线程的调用。

  6. 线程 图表的当前比例不允许我们详细查看 13456 线程池 (我们的 BackgroundWorker 线程)。 让我们放大以适应整个图表。 为此,请在 线程 图表上使用 鼠标滚轮 。 这会自动添加按可见时间范围的过滤器: 1489 毫秒。 注意此过滤器如何影响其他过滤器:所有值都会根据可见时间范围重新计算。 当前应用于快照数据的过滤器为: "选择所有线程在可见时间范围内的时间区间,隐藏的除外"

    t1_visible_interval_filter.png
  7. 查看 线程 图表。 您看到的是线程状态随时间的变化。 例如,我们的 BackgroundWorker 线程 13456 线程池 大约在 16 秒时开始(在我们点击 处理文件 按钮之后)。 大部分时间线程处于 正在运行 状态(深蓝色区间)。 此外,还有一些区间线程处于 正在等待 状态(浅蓝色区间)。 t1_zoomed_thread.png

  8. 查看 线程 工具窗口中的 Process Overview 图表*。 除了 CPU 利用率外,它还显示了两个事件图表,这对于性能分析可能非常有帮助。 UI 冻结 条显示卡顿在 13456 线程池 创建后立即开始。

    在此时间区间内还密集地执行了阻塞垃圾回收 垃圾回收。 由于阻塞 GC 会暂停所有托管线程,它可能是 UI 卡顿的潜在原因。

    我们必须更仔细地查看这些事件。

    t1_process_overview.png
  9. 首先,让我们移除可见时间范围过滤器,因为我们不再需要它。 为此,请点击 线程 工具窗口顶部的过滤器*。 图表将缩小回原始比例。

    t1_remove_filter.png
  10. 现在,让我们更深入地研究 UI 卡顿事件。 这些卡顿的主要潜在原因是什么? 它们是:

    • 长时间或频繁的阻塞 GC;

    • 某个其他线程阻塞了 UI 线程(例如,由于锁争用);

    • 和/或在 UI 线程上进行过多的计算工作。

    我们将逐一排除这些原因,直到只剩下真正的罪魁祸首。

  11. 通过点击 线程 工具窗口的 Process Overview 部分中对应的条形图,选择 UI 冻结 事件。 这将应用按 UI 卡顿事件的过滤器。 请注意,这不仅应用了按卡顿时间范围的过滤器,还应用了按 主要 线程的过滤器。 后者是自动完成的,因为主线程是我们应用程序中唯一处理 UI 交互的线程。 因此,当前的过滤器为: "选择主线程上发生 UI 卡顿事件的所有时间区间"

    t1_ui_freeze_filter.png
  12. 现在,为了确定此次卡顿的真正原因,让我们调查其他过滤器值。 我们应该分析的第一个潜在原因是过多的阻塞 GC。

    点击 阻塞 GC 打开阻塞 GC 过滤器并查看值。

    考虑到当前应用的过滤器,它显示了在卡顿期间主线程被 GC 阻塞的时间(阻塞 GC 值)和未被阻塞的时间(排除阻塞 GC 值)。

    t1_blocking_gc_filter.png

    阻塞 GC 时间相当高(420 毫秒,占选定区间的 10.2%),可能对性能有一定影响。 然而,它几乎不可能是 4 秒卡顿的原因。 因此,我们可以将过多的垃圾回收从嫌疑列表中排除。

  13. 点击 排除阻塞 GC 值。 当前的过滤器为: "选择主线程上发生 UI 卡顿事件且未执行阻塞 GC 的所有时间区间"

  14. 让我们调查潜在原因“被其他线程阻塞”和“主线程上的过多工作”。

    打开 线程状态 并查看值。 此过滤器显示线程在某种状态下花费的总时间。 考虑到当前应用的过滤器,它显示了主线程在卡顿期间的状态。

    t1_thread_state_filter.png

    似乎大部分卡顿时间(92.9%3426 毫秒 ),线程正在执行某些工作,因为它处于 正在运行 状态。 225 毫秒 状态的 正在等待 值太小,这自动将“被其他线程阻塞”从潜在原因中排除。 因此,卡顿的原因只能是主线程上的计算工作!

    我们现在需要做的就是找到在卡顿期间在 主要 线程上执行的方法。 我们可以使用 热点调用树 过滤器来完成此操作。

  15. 线程状态 过滤器中选择 正在运行。 这将使当前的过滤器为: "选择主线程在发生 UI 卡顿且未执行阻塞 GC 时运行的所有时间区间"。 过滤器列表如下所示:

    t1_applied_filters.png

    现在,过滤器 热点调用树 仅包含在这些时间区间内执行的方法。

  16. 性能分析器 窗口中,点击 热点 打开相应的过滤器。 它显示了按执行时间排序的用户方法的简单列表。 用户方法的执行时间是通过将方法自身时间与其调用的所有系统方法的自身时间(直到堆栈中的下一个用户方法)相加计算得出的。

    t1_top_methods.png

    如您所见,只有两个方法具有有意义的执行时间: App.MainMainWindow.ProcessInProgress

  17. 查看 调用树

    t1_call_tree.png

    如您所见, App.Main 大部分时间都花在了一些与处理 Windows 消息相关的系统方法中。* 这是任何提供图形用户界面的应用程序的典型行为。 这表明应用程序在消息循环中等待用户输入。 在分析快照时,我们可以简单地忽略这些方法。 要找出导致卡顿的方法,我们应该查看堆栈中的下一个用户方法,结果是 MainWindow.ProcessInProgress。 由于我们假设卡顿是由于此方法中的某些计算工作引起的,让我们检查其源代码。

  18. 调用树 中,右键点击 ProcessInProgress 方法并在上下文菜单中选择 导航到代码

    t1_navigate_to_code.png
  19. 查看源代码。

    private void ProcessInProgress(object sender, ProgressChangedEventArgs e) { var upd = (ProgressUpdater) e.UserState; lblProgress.Content = $"File {upd.CurrentFileNmb} of {upd.TotalFiles}: {e.ProgressPercentage}%"; }

    看起来此方法只是一个事件处理程序,用于更新主窗口中进度标签上的文件处理操作进度。 这些计算看起来并不复杂,那么为什么会发生卡顿呢? 显然,这个事件处理程序被调用的频率太高,以至于主窗口无法应对标签的更新。 让我们在代码中检查一下。

  20. 进一步的代码调查*显示,这个事件处理程序订阅了后台工作线程的 ProgressChanged 事件。 当工作线程调用 ReportProgress 方法时,会触发此事件。 反过来,它是从后台工作线程的 ProcessFiles 方法中调用的。

    ... for (int j = 0; j < _lines.Length; j++) { var line = _lines[j]; var stringReverser = new StringReverser(line); _lines[j] = stringReverser.Reverse(); if (j % 5 == 0) { var p = ((float)(j + 1) / _lines.Length) * 100; Worker.ReportProgress((int) p, _updater); } } ...
  21. 这是我们性能问题的原因:每处理 5 行文本文件时都会调用 ReportProgress。 由于行处理速度非常快, ReportProgress 被系统调用的频率过高。 让我们降低这个频率,例如,每处理 1000 行调用一次。 改进代码中的 if 条件。

    ... if (j % 1000 == 0) { float _p = ((float)(j + 1) / _lines.Length) * 100; Worker.ReportProgress((int) _p, _updater); } ...
  22. 重新构建解决方案,并按照 运行分析器并获取快照 中的描述再次进行分析。

    t1_threads_fixed.png

    不再有卡顿! 时间线也未检测到文件处理期间的任何 UI 卡顿。

结论

以下是本教程的主要收获:

  • 与“经典”性能分析不同,在时间线分析期间,dotTrace 收集了临时调用堆栈和线程状态数据。

  • 要分析时间线分析的结果,您可以使用 Visual Studio 中的 性能分析器 工具窗口或独立的 dotTrace Viewer 应用程序。

  • 性能分析器dotTrace Viewer 是一组过滤器和图表,可视化应用程序的事件时间线,并允许您切片和分析收集的临时数据。

  • 每个过滤器都有双重用途:既显示数据又允许您设置特定条件。

  • 过滤器可以组合使用。

最后修改日期: 2025年 9月 28日