【Fundamentals of Windows Performance Analysis】翻译,第四章: 基本定界
在第2章中,我们介绍了一些可以用来监视和/或分析系统性能的内置工具。 我们还回顾了Windows的性能计数器(PCW)和Windows的事件跟踪(ETW)之间的区别,并学习了如何使用这两种技术收集性能日志(即Trace)。 最后,我们得出结论,ETW更适合于定位复杂的性能问题,而PCW在监控长时间活动方面更有价值。 然后在第三章中,我们展示了如何使用WPR收集ETW性能日志。
在本章中,我们将继续构建我们的ETW处理技能集。 我们将从学习如何在数据的海洋中定位。这是他们通常带来的。 回想一下,ETW性能跟踪本质上是各种系统和第三方组件记录的带有时间戳的事件的集合。 WPA帮助拼凑所有这些数据,并在时间轴上方便地可视化它。 正如您将看到的,知道要关注时间轴的哪个时间范围对于从根本上造成性能问题是至关重要的。 我们将把这些时间范围称为感兴趣的区域,并通过一系列相互构建的简单示例展示,识别这些区域如何有助于发现它们内部的性能问题和根本原因
感兴趣的区域可以表示系统活动(例如进程生命周期)、用户活动(例如焦点中的窗口)或应用程序活动(例如函数调用)。 此外,不管用户是什么,感兴趣的区域也可以表示资源使用情况(例如,高磁盘使用vs.低磁盘使用区域)。
那么这些感兴趣的区域从何而来? 其中一些来自现有的系统范围的ETW检测,如表示GUI延迟的标记、进程生命周期、焦点窗口、二进制文件加载等。 其他的可以由单个系统组件(如处理器功率管理器(PPM)或服务控制管理器(SCM))记录的ETW事件构造。 还有一些可以由用户应用程序(如Internet Explorer和Media Player)记录的事件形成。 事实上,正如您将在本书后面看到的,任何应用程序(包括您的应用程序)都可以记录ETW事件。 我们将用一对启动/停止事件显式划分的感兴趣区域称为感兴趣的属性区域。
不是所有感兴趣的区域都明确地受到ETW事件的约束——有些对应于资源使用率高或低的区域,或者是已知的“感兴趣”事件或模式的邻近区域。 如果在这一点上,这些示例听起来与实际情况脱节——请不要担心——在本章中,我们将引导您通过实践练习,演示如何在定位性能问题的时候使用显式和隐式感兴趣的区域
感兴趣的属性系统活动区域
正如我们所提到的,Windows自带的检测工具可以帮助识别许多感兴趣的基本区域,这些区域可以作为终端用户活动的良好代理。 这些区域包括表示进程生存期、UIdelay和焦点窗口的时间间隔。 通常,我们感兴趣的是关注这些区域的子集,因为它们与问题中的用户场景很好地对齐。 下面的练习将演示如何识别这些基本系统概念感兴趣的区域。 在开始练习之前,让我们首先快速回顾一下这些概念,以及它们对性能分析的重要性。 如果你已经熟悉这些概念,可以直接跳过这个练习。
进程
在计算机发展的早期,计算机一次只执行一项任务。 多个任务被分批处理并按顺序执行。 在不同的任务之间共享计算机时间的需求催生了如Windows的多任务操作系统。 这里出现了两种形式:协作式多任务调度模型和抢占式多任务调度模型
在协作模型中,每个任务都应该是一个好公民,并在合理的时间内将CPU时间留给其他任务。 “合理”的定义则留给系统用户(例如应用程序)。 很容易看出这个模型在性能上是如何崩溃的。 相反,在抢占模型中,操作系统充当仲裁人,决定哪个任务在哪个CPU上运行以及运行多长时间,可能在其他任务执行过程中抢占它们。 使用此模型,单个应用程序接管整个系统变得更加困难。
随着任务复杂性的增加,需要将它们进一步分解成子任务。 这些子任务本质上每个子任务都表示一个执行流,所有子任务都托管在一个父容器任务中。 在主流操作系统中,进程作为父任务的容器,线程作为子任务的容器。
使用这个术语,当用户希望通过启动应用程序来执行给定的任务时,操作系统会创建一个进程,在该进程中创建一个线程(然后可以创建更多线程)来执行该应用程序的代码。 每个进程都由一个惟一标识符标识,通常称为PID(进程ID)。 这个ID是在进程创建时分配的,并在其整个生命周期中持续存在。
注意:PID可以被新创建的进程重新使用——这就是为什么通常需要PID和进程创建时间的组合来唯一标识一个进程。
正如我们将在下面的练习中看到的,Windows自带一个ETW Provider,它提供了一种简单的方法来收集关于哪个进程在什么时间运行的信息。 更好的是,WPA还提供了易于使用的图表,帮助您可视化这些信息。 在本书的后面,我们将带您通过类似的步骤来查看线程生命周期信息。
窗口焦点
正如我们提到的,Windows是一个多任务操作系统。 简而言之,这意味着许多进程同时执行,并发地共享系统硬件和软件资源。 然而,对于人类来说,往往很难同时专注于许多事情,所以我们倾向于专注于手头的一项任务。 因此,当与计算机交互时,用户在任何时间点通常与单个应用程序交互,或者更确切地说,与该应用程序中的单个窗口交互。
在出现性能问题时,知道哪个应用程序窗口处于焦点位置,并计算出导致问题的用户交互窗口的确切顺序,对于报告的问题的根源来说是非常有益的,有时是至关重要的。 即使用户提供了问题的描述,这种描述也只是一种感知,而感知可能是不准确的。 例如,用户可能会忽略他们曾经切换到不同的应用程序这一事实。 如果该应用程序为了显示其内容而需要执行一些工作,那么这可能会导致问题。
您可能还需要知道哪个窗口在什么时间处于焦点中,以便确定给定的UI延迟是否导致了用户可感知的问题。 当用户描述问题时,这些小细节往往会被遗忘和/或省略,尤其是当他们对自己的电脑问题感到情绪激动时(而且大多数人确实如此)。
为了帮助解决这个问题,我们将在下面的练习中看到,Windows有一个ETW提供程序,它提供了一种简单的方法来收集在什么时间哪个窗口处于焦点中。
UI延迟(UI delays)
当应用程序的UI或系统本身出现明显的延迟时,用户通常会抱怨性能。 事实上,这些延迟在某些应用程序中非常常见,从Vista发布开始,Windows就将处理超过500ms的Windows消息的延迟视为“无响应”,并将内容停止更新的窗口幽灵化,如图4.1所示。
注意:对于幽灵窗口,桌面窗口管理器还会在窗口标题中添加“(未响应)”,以更清楚地表明应用程序UI未响应,无法交互。
注意:正如我们在本书后面会看到的,任何超过500ms的延迟都被认为是不可接受的,用户交互应该让用户感到及时响应
应用程序的响应性是通过其处理窗口消息的延迟来度量的。 因为所有的Windows GUI应用程序都有一个循环来处理窗口消息,比如输入和绘制,所以将应用程序的响应性与操作的这一关键部分绑定是合理的。 这个循环通常被称为消息泵。 可见前景窗口的消息处理中的任何延迟,都不可避免地直接转换为该窗口的用户感知到的延迟。
注意: 幽灵窗口机制要归功于windows vista引入了桌面窗口管理器(dwm)。这样即使一个窗口未响应,操作系统还是可以继续在桌面上显示其他内容(这个将在第6章详述)。Vista之前, 应用程序习惯于将其窗口内容直接呈现到屏幕上,因此Windows无法轻松地增强用户对应用程序窗口的体验 。
注意:应用程序窗口幽灵化并不一定意味着应用程序本身hung死。 通常情况下,如果您等待的时间足够长,它的UI将再次响应。 然而,这样的体验会让用户非常沮丧,所以无论如何都要避免。 如果您正在分析用户面临的性能问题,那么很可能会看到UI延迟。 如果您在应用程序中发现它们,请修复它们。 我们在这里能给出的最好的通用建议是,在GUI线程中只保留对ui至关重要的工作。 将所有其他密集型活动放到其他线程。
注意:知道什么要在UI线程上保留,什么要卸载是一个平衡练习,这并不总是微不足道的。 请记住,将一些操作卸载到另一个线程实际上可能比在原始处理线程上快速处理它们代价更高。
现在我们已经了解了最重要的系统活动,接下来让我们快速回顾一下如何选择WPA中感兴趣的区域。 有关更深入的详细介绍,请参阅附录A。
选择感兴趣的区域 (Selecting regions of interest in WPA )
有两种方法选择感兴趣的区域,典型的:
- 时间序列选择
- 数据序列选择
使用时间范围选择,可以在图上拖动选择,定义感兴趣的连续区域。 典型的应用包括基于视觉线索从a点到B点选择一个区域。 这些线索可能来自显式记录的事件,也可能来自识别可视化数据系列中的特定模式。 在后面的练习中,我们将看到多个这样选择的示例。
对于数据系列选择,只需单击图例控件或表中的给定元素(也可以进行多选)。 正如我们将看到的,WPA随后还根据底层数据为各自感兴趣的区域生成选择 。
注意:从数据系列选择中创建的感兴趣区域可以使用属性数据或抽样数据形成。 在属性的情况下,将记录不同的事件,以表示区域的确切边界。 在抽样的情况下,收集多个数据样本,然后基于一个断言评估,以确定它们是否对感兴趣的区域有贡献。 在下面的练习中,我们将看到有关属性区域(例如UI延迟)和采样区域(例如采样CPU使用率)的例子。 要了解更多细节,请参阅第二章的“抽样vs.归因”章节。 在第7章、第8章和第9章讨论处理器性能分析时,我们还将更仔细地研究这两种度量方法之间的实际差异,这两种方法都大量使用。
练习4.1:在典型的性能跟踪中识别感兴趣的基本区域
在这个练习中,我们将看到如何在典型的性能跟踪中识别感兴趣的区域,您将在本书中反复应用这项技能。 这也是在现实世界中练习性能分析时首先要做的事情之一。 具体来说,我们将检查当我们在记事本中打开一个非常大的文件时发生了什么,因为它变得无响应 。
正如本书其余部分所述,我们将使用免费的WPR和WPA ETW工具进行调查。 与具有简单的跟踪捕获UI的WPR不同,WPA是一个复杂的工具。 为了帮助您轻松地使用它,本书通过贯穿全书的练习逐步介绍了它的大部分功能。 附录A是对WPA的系统概述,包括全书中提到的内容以及我们在练习中没有强调的功能。
概述
这个示例使用名为fsutil的系统实用工具创建了一个500MB的data.txt文件。 然后使用记事本打开该文件,导致记事本在打开这个大文件时失去响应。
问题表现
正如我们看到的,当打开一个非常大的文件时,记事本变得没有响应。 正如我们前面提到的,每当应用程序变得无响应时,Windows就会隐藏其窗口并将(无响应)添加到其标题中,如图4所示。
无响应的应用程序通常是性能问题的一个很好的指示器。
注意:当应用程序变得永久无响应时,通常意味着它是一个死锁问题,这更偏向功能问题,而不是性能问题。 另一方面,临时无响应的应用程序显然更偏向于属于性能问题。
分析方法
这本书有预先抓取好的log,所以你不必花时间为这个和其他练习捕获log。 然而,为这个练习捕获您自己的trace还是非常有价值的 。因为它将帮助您建立对端到端性能分析工作流的信心。 在我们完成这个练习的分析方法之后,我们将在另一个部分向您展示如何为这个场景捕获您自己的trace(译注:最新win10版本打开一个500M的大文件已经不会出现未响应)。
本节描述如何在记事本中检查和评估加载一个非常大的文件。
- 打开etl文件
- 虽然这不是你能看到的最大的trace,但它包含了很多活动,为了有效地分析它的内容,我们需要知道在哪里集中我们的注意力。 WPA提供了许多不同的详细图表,您可以利用它们进行分析。 这些图被组织成特定于它们所代表的数据的组。 这些组织包括:
-
表示CPU活动的Computation图
-
表示在存储设备上活动的Storage图
-
可以表示在任何时间点的内存使用的Memory图
-
可以帮助您了解在日志记录区间发生了什么网络活动的Network图
-
显示系统功耗情况的Power图
-
我们将在后面的练习中简要地看一下这些图表,并在本书后面的章节中花整章的时间讨论其中的一些组。
- 还有一种特殊类别的图称为系统活动图(System Activity),它包含几个图,告诉您在记录跟踪时系统上发生了哪些逻辑活动
- WPA在一个实时缩略图中组织所有可用的图,为您提供完整图的预览。 这些顶级实时缩略图也被称为kpi或关键性能指标(Key Performance Indicators),因为它们可以让您快速了解资源使用情况,而无需查看底层的详细图表。
- 这些实时缩略图可以帮助您选择您想要查看的图表。 要访问这些图,您可以使用Graph Explorer(默认情况下)停靠在WPA主窗口的左侧。 让我们首先通过展开System Activity组来仔细查看图,如图4.3所示。
进程生命周期查看
- 在图4.3中,我们可以看到许多可用的图,每个图都表示跟踪中的一些有价值的信息。 让我们从查看进程图(Processes)开始。 为此,双击其预览缩略图或将其缩略图拖动到右侧的空白区域,正如我们在上一章中所说的,这被称为分析视图。 完成后,您将看到如图4.4所示的视图。
注意:人们常犯的一个错误是试图拖动图形的标题,这是在本书写作时,没有预期到的情况。
-
在我们看这个图表告诉我们什么之前,让我们先花一些时间来理解一个详细的图表是由什么组成的。 图4.5显示了三个基本构建块,它们构成了你将在WPA中看到的每个详细图表
-
图形数据视图(Graphical data view),或者叫图形(graph),对应的可视化底层数据,显示在表格数据视图(Tabular data view)中,简单成为表格(table)中。 当选择一个区间范围后,这两个视图是同步的。 数据通常以表中金线左侧的一个或多个维度为中心,并在金线右侧聚合。 例如,在图4.5中,进程生命周期数据由生存期类型(暂时的(Transient)和永久的(Permanent)和进程名称来决定。 图4.5中的金线右侧的数据对每一组进行了聚合,例如,暂时的进程的总持续时间Duration(s)Sum值是单个暂时的进程的所有持续时间之和。
在接下来的章节中,我们将提供预置的汇总方法,但你也总是可以自己重新创建它们。 我们将在附录A中更详细地讨论WPA详细图的原理。
-
请注意,您可以通过拖动分隔这些块的边界线来调整这些块的大小,以显示更多或更少的数据。 事实上,图4.5中的legend控件在默认视图中不够大,无法向我们显示所有的瞬态进程及其长名称,所以让我们调整它的大小,如图4.6所示。 暂时的(Transient)进程是所有在收集日志期间启动和/或退出的进程
注意:图中右侧标题为Trace Rundown的灰色区域(图形数据视图的尾部的一个矩形区域)是ETW跟踪会话停止的时间段。 如果会话正在内存中收集数据,那么在此期间收集的所有数据都会被刷新到磁盘。 由于刷盘是磁盘I/O和/或CPU密集型活动,因此会影响度量。 因此,在分析中最好忽略这一部分。 除了影响度量之外,这段时间WPR会逐个关闭启用的ETW提供程序,因此不能保证您正在寻找的事件会出现在跟踪的这一部分中 。
-
这个图告诉了我们什么? 回想一下,在第2章中,当我们使用不同的工具来诊断CPU饱和导致的系统减速时,我们查看了系统上运行的所有进程。 这些工具中的每一个都以略微不同的方式表示流程信息。 我们看到系统上有很多正在运行的进程,它们共同消耗了系统资源。 WPA也不例外,它为您提供了一个很好的视图,让您了解哪些进程在系统上运行。 事实上,您不仅看到了哪些进程存在,而且还看到了它们在您的记录期间何时启动和终止
注意:其中一些(瞬态)进程是在记录期间创建和/或终止的,而其他(永久)进程则存在于整个跟踪过程中。 Processes图通过将它们分组向您展示了这两种情况。 默认会聚焦在瞬态进程图,因为通常瞬态记录会更活跃。
-
想一下我们为什么要进行trace -- 当打开一个大文件时记事本未响应。 要从根源上找出这个问题的原因,我们首先需要找到记事本在跟踪中何时运行,而流程图正是为此而设计的。 最简单的方法是通过点击legend控件中的Notepad .exe条目选择Notepad,如图4.7所示。
-
我们选择的进程对应的投影现在出现在分析视图底部的时间轴上。 它显示了Notepad在记录的trace中运行的确切时间。 您还可以清楚地看到在那段时间内存在的其他过程,正如我们稍后将看到的那样,这些过程可能对记事本的执行产生了实质性的影响
-
trace的开始表示为时间0,然后所有其他活动的时间戳都与之相关
注意:在图4.7中,您可能已经注意到Start时间戳不是精确的零,而是~0.0529s。 这是由于WPA将视图的左侧剪切到跟踪中的第一个事件(在本例中是这样)造成的 。既在跟踪开始后的0.0529s的时候收到了第一个事件。 在使用循环缓冲区跟踪时,您可能会更好地欣赏这个有用的特性,在循环缓冲区跟踪中,记录持续了数小时,但只有最后几分钟的事件才能打到最终的Log里面。
焦点窗口
-
进程生命周期是否是用于标识日志中感兴趣的区域的良好度量? 这是一个很好的开始,但是请记住,应用程序不一定要在前台才能运行。 事实上,记事本可以隐藏在其他窗口后面,或者最小化,用户只在其生命周期的一小部分时间内与它进行交互。 显然,如果我们看看Notepad在什么时候在前台,我们可以做得更好。
-
碰巧WPA有一个这样的图表,叫做焦点窗口图(Window In Focus)。 您可以通过双击其预览缩略图或拖动它,将其添加到分析视图,类似于Processes图。 完成之后,您将看到如图4.8所示的视图。
-
正如你所看到的,WPA要显示的数据比屏幕上的空间多得多。 无论您的显示器有多大,最终您都会遇到屏幕空间的限制。 幸运的是,就如何在屏幕上安排数据而言,WPA非常灵活。 当前我们并不太在意关于Processes图中的表格数据视图,所以让我们通过单击图标折叠它(有关WPA图管理的详细信息请参见附录A)。
-
新添加的图展示了所有的时间点,分别是哪些应用程序处于焦点状态。
-
注意,我们首先与WPR GUI进行交互以开始录制,然后切换到控制台(conhost.exe)来启动我们的练习脚本。 脚本然后启动Notepad (Notepad .exe)。
注意:Focus图中的Window不会显示无窗口的进程(例如命令行工具)。 因此,即使我们在启动记事本之前运行两个fsutil.exe进程实例来创建data.txt文件,您也不会在这个图中看到它们
-
现在我们到了有趣的部分。 当记事本运行时,图表显示一个名为dwm.exe的进程将焦点从记事本上转移开。 这个进程是什么? 当记事本运行时,我们有没有看到其他应用程序进入前台? 没有,但我们确实看到窗户被幽灵化了。
-
DWM代表桌面窗口管理器,它是Windows桌面表示子系统背后的组合引擎。 当有窗口的应用程序变得无响应时,DWM负责将自己的窗口放在无响应的应用程序窗口的顶部,以显示该应用程序渲染的最后一张图像的幽灵版本。 它还将(未响应)文本添加到窗口的标题中
-
那么,DWM在焦点上的时间是否代表Notepad没有响应的时间区域呢? 嗯,有点。 DWM只会在用户试图与之交互时把窗口幽灵化。 毕竟,除非它影响到用户,否则揭示这个问题是没有价值的。 那么我们如何找到Notepad失去响应的时间区域 ?
UI delays
-
为了查看给定窗口应用程序何时没有响应,WPA提供了UI Delays图。 这个图非常有用,事实上,每当日志中出现任何UI延迟时,都会将System Activity KPI图放在图组的顶部
-
图4.11显示了我们将UI Delays图添加到分析视图中,并调整其他图的大小,以帮助将所有三个详细图放入视图中。 注意,为了适应屏幕截图中的所有三个图表,我们隐藏了前两个图表的表格
-
当任何给定的窗口应用程序在一段特定的时间内没有处理windows的消息时,就会被检测到未响应,并记录一个ETW事件。在本书的后面,我们将看到响应在可接受延迟方面的真正含义。 然后,WPA使用这些事件来绘制表示时间轴上相应延迟的区间。 当然,在与无响应UI相关的性能分析调查期间,这些间隔是感兴趣的区域的主要候选区域 。
-
你会注意到notepad.exe进程实际上是两个元素的折叠组(在图例和表中)。 您可以通过单击notepad.exe左边的图标来展开它。 你会看到类似于图4.12所示的内容,即你会发现两个不同的延迟,即MsgCheck延迟和Input延迟
-
MsgCheck延迟表示窗口应用程序不处理传入窗口消息的时间区间。 Input延迟表示用户意识到应用程序没有响应的实际时间,因为他/她试图与应用程序的窗口交互,即此时开始在点击窗口
-
这就是我们对WPA中三个主要的感兴趣区域图的回顾。 我们将使用这些图来帮助找到感兴趣的区域,以便在本书的轨迹中进行详细的分析。
您将注意到前台和后台应用程序都记录了UI延迟。 由于用户关心的是这些窗口的响应性,所以一般来说,您应该关注前台应用程序中发生的延迟
注意:当捕捉包含在书中的痕迹时,在尝试与记事本的窗口交互之前,我们已经等待了大约四秒钟。 这与图4.12中相对于MsgCheck延迟开始的Input延迟紧密对应,从图中可以看到,MsgCheck延迟是在应用程序启动时开始的。 如果您手动打开记事本,然后使用它的文件|打开菜单选项打开大文件,您将看到MsgCheck延迟在应用程序启动后才开始。
自己尝试复现一下上述问题
既然您已经使用我们包含的跟踪完成了整个练习,我们建议您对自己的跟踪重复这些相同的分析步骤,并观察哪些问题再次发生,哪些问题没有发生。 也可以在您自己的跟踪中寻找其他问题
-
打开WPR
-
勾选 First Level Triage, 详细级别选择Verbose
-
在Resource Analysis选项中,勾选Disk I/O Activity、File I/O activity、 Resident Set Analysis
-
开始记录
-
管理员权限打开控制台
-
运行如下脚本:
REM create a new file fsutil file createnew data.txt 500000000 REM set the valid data length fsutil file setvaliddata data.txt 500000000 notepad data.txt del data.txt
-
这个脚本创建了个500MB的文件并打开它
-
等几秒钟后点击记事本窗口,你将会发现它被幽灵化了
-
当记事本再次可以响应的时候,关闭它,然后脚本最后会把临时创建的大文件删除掉。
-
保存这份WPR日志。
现在,你可以尝试用同样的分析步骤来再次定位下这个问题。
关键点
现在我们回顾一下至今为止所学:
- 想要定位性能日志的根因,当务之急是找到看哪个区域,既识别关键区域。
- 左侧罗列各项概要信息,可以从中选择自己需要的
- WPA中的Graph Explorer按关键区域将可用的详细图组织成逻辑组,每个组由关键性能指标(KPI)图表示 。
- System Activity组提供了对几个关键区域的入口,包括焦点窗口、进程生存期和UIdelay
- WPA支持显示仅图形、仅表格、图形表格混合视图
- 可以将多个WPA图添加到同一个分析视图中,所有图都共享相同的时间轴
到目前为止,我们已经看了许多示例,演示了您在处理性能跟踪时可能会发现有用的基本感兴趣区域。 所有这些区域都在操作系统中被显式地检测,并被记录为ETW事件,供WPA在可视化中使用。 如前所述,我们将这些区域称为属性系统区域(attributed system regions)(之所以叫属性attributed是因为系统通过使用一个事件来标记区域的结束及其持续时间或两个特定事件标记区域的开始和结束,为这些区域赋予了语义意义)。
一旦我们发现了一个感兴趣的区域,我们通常想知道在那个时期发生了什么。 请注意,有时您无法享受到这些感兴趣的属性区域,必须尝试使用资源使用视图来确定您的注意力集中在哪里。 正如我们将看到的,这些区域通常是隐式的,因为它们没有专门的边界事件。
在下一章中,我们将继续分析Notepad无响应的根本原因,重点是我们在练习4.1中确定的UI延迟期间的资源使用。 事实上,为了帮助我们更好地理解记事本是如何打开一个大文件的,我们接下来需要研究它对不同资源的并发使用 。