Windows下生产环境性能诊断利器 - PerfView

为什么是PerfView?

PerfView是Windows下性能诊断的利器。特别对于生产环境,如果我们想Profiling生产环境运行的程序,需要这个工具达到以下要求:

PerfView完美达到的以上的要求,可以attach到已经运行的进程(包括整个系统所有进程)之上,并且性能很好并不会对正在运行的程序产生显著影响(使用默认选项采集的话在5%-10%的性能影响)。另外PerView可以xcopy到生产环境的机器上直接运行。

PerfView介绍

想要知道什么PerfView,需要对ETW即Event Tracing for Windows有所了解。ETW的结构如下:

etw-architecture.gif

简单来讲Controller就是通过Trace Session来控制事件打开和关闭的,Provider是事件提供者,提供的东西就是一个个的Event(Event是一些基础元信息,比如进程ID,线程ID,函数调用信息,时间等,加上一些应用特定的Playload,即:

Event = Metadata + Payload

重要的是,Windows 7以后的系统中,系统组件内置丰富的Provider,几乎涵盖Windows系统的方方面面。比如进程,线程的创建销毁,文件,网络IO,对于.NET Runtime来讲提供了.NET下的性能计数,内存管理事件等等。几乎你想要的都可以找到。

不仅如此从.NET Framework 4.5之后,还提供了EventSource类型。我们可以很容易在自己的应用中集成Event Sourcing用来发布我们自己的事件。

PerfView在这个架构中充当了Controller和Consumer的角色:

Profiling有两个要点,PerfView都可以完成:

使用PerfView采集数据

对于性能诊断和调优大体上归结为两类:运行时间,内存消耗。即我们的程序是不是在预定的时间内完成任务,或者虽然完成了工作,但是消耗的内存超出实际需要。

在PerfView中分别有两个菜单来分别对应即Collect和Memory。在Collect菜单中还有一系列选项可以用来调整在采集数据中你需要关心的点。这样可以尽量收集自己感兴趣的信息。对于CPU问题,我们可以勾选Thread Time选项,这样我们可以看到每个函数所花费的CPU时间,包括等待文件和网络IO时间。PerfView提供了很好的统计,过滤选项,可以快递定位时间消耗的发生点,给后面的程序优化提供信息。

Windows的虚拟内存机制为我们提供了线性地址空间。使用Memory菜单,我们可以直接采集某个进程的Memory Heap Snapshot。更方便的是我们可以采集两个时间点的Snapshot,然后在PerfView中进行diff。对于内存泄露类的问题,这样很容易找出导致内存泄露的对象。

在生产环境,我们还是用命令行进行自动化,来采集我们的关注点。比如监测IIS访问超过10秒时间,可以通过下面的命令在服务器上进行监测:

PerfView collect -StopOnRequestOverMSec:10000 -AcceptEula -NoView -CollectMultiple:2 -LogFile=Log.txt -ThreadTime SlowRequests.etl

我们来看看我们设置的选项:

Perfview有个-Rundown选项,通常采集时候不要指定这个选项。这个NoRundown的意思是不进行符号的解析,符号解析对我们分析问题十分有帮助。

/NoRundown to the commandline which means we are not getting some managed call frames (ie, moduleA!? instead of something like moduleX!methodFoo(argType))

使用PerfView分析CPU问题

采集完成后,我们可以打开PerfView,在左边的选择采集到的ETL文件。

1.select.w3wp.png

双击选中IIS后,进入下面的界面:

2.await.png

从上图中,我们可以看到访问的Url(第一栏向左拉一点)。其实个界面中其实有一点迷惑,如果你选中上图的Advanced Gropu -> Asp.Net Stat你会发现最长的用时不过18秒多。这里面为什么Request有35多秒?,但是Threads时间看上去对的上的。这里面PerfView把Threads和SQL Activity时间汇总,因为SQL是发生在另一个进程里面的,所以这里面不应该加到这个Request上。更进一步,我们看看Thread都在做什么?

3.blocked.png

仔细的drill into后,你会发现其实是Thread发生了AWAIT,在等待什么东西完成。我们在打开看看SQL Activity发生了什么,这时候可以看到某条SQL花费了17秒多。结合上面的Thread等待,我们推断是上面的Thread在等待这条SQL执行。

更进一步的,我们可以通过点击Activity SQL Command查看到发起这个SQL的Call Stack,至此问题找到了:我们的页面渲染访问了一个SQL,这里SQL耗时17秒多。

4.root.cause.png

使用PerView分析内存问题

TODO

常见问题

  1. 为什么我分析的时候不显示具体的函数名?
    • 关闭-NoRundown选项
    • 检查网络-时常是网络的问题
    • 查看Log窗口。

参考

@ 2020-04-29 09:20

Comments:

Sharing your thoughts: