前言
在现代的容器化和微服务应用中，因为分布式的环境和错综复杂的调用关系，APM（Application Performance Monitoring 应用性能监控）显得尤为重要，它通过采集应用程序各种指标和请求链路，让你知道系统当前的状态和值得优化的点，另外能帮助你发现应用程序的异常，帮助你更方便的定位问题。
对于.NET这样带GC（Garbage Collector 垃圾回收器）的平台来说，GC的指标也尤为重要，采集可以帮助我们分析内存泄漏、优化系统性能等等。在公司内部已经可以采集比较全面的.NET GC指标，如下图所示。.
在绝大多数场景它能满足要求，但是如果遇到某时某刻P95延时突然增大，异步任务突然超时，我们想排查这些异常是否因为GC的STW Time（Stop The World Time 指GC运行过程中所有线程被挂起的时间）过长导致的，就没有办法了，因为目前没有采集这些指标。
所以本文就带大家了解一下，如何采集.NET GC STW Time。
方法
如.NET内存性能分析指南中提到的一样，.NET Runtime在运行过程中会发布很多事件，这些事件代表了当前Runtime的运行状态，同样GC在运行过程中也会发布很多事件，我们可以使用PerfView工具来收集这样的一些事件。下面是WorkStationGC发生GC时的一个事件序列。
Microsoft-Windows-DotNETRuntime/GC/SuspendEEStart //开始暂停托管线程运行Microsoft-Windows-DotNETRuntime/GC/SuspendEEStop //暂停托管线程完成Microsoft-Windows-DotNETRuntime/GC/Start // GC开始回收Microsoft-Windows-DotNETRuntime/GC/Stop // GC回收结束Microsoft-Windows-DotNETRuntime/GC/RestartEEStart //恢复之前暂停的托管线程Microsoft-Windows-DotNETRuntime/GC/RestartEEStop //恢复托管线程运行完成
PS: 所有的事件都可以在.NET文档官方中找到，非常的全面。
而SuspendEEStart(暂停托管线程运行)到RestartEEStop(恢复托管线程运行完成)中经过的时间就是STW Time，我们只需要记录这两个事件的差值，就可以知道本次GC STW的时间有多长。
BGC的过程比WorkStationGC复杂的很多，但是一样是测量这两个事件花费的时间来采集STW Time，本文不做过多介绍。
使用EventSource采集
那么我们知道通过计算哪两个指标的差值来获得STW时间，那么应该如何通过代码来采集呢？
这里就需要知道EventSource和EventListener两个类，顾名思义我们可以通过EventSource来发布事件，使用EventListener来监听事件，在本文中我们也主要使用EventListener来收集GC事件，对于这EventSource类的使用大家可以看下面给出的微软文档链接，这里不做过多介绍。
-
EventSource
-
EventListener
我们来看一看如何使用EventListener类监听GC事件，代码如下所示：
using System.Diagnostics.Tracing;// 开启GC事件监听 var gc = new GcStwMetricsCollector();// 创建一些对象 var array = Enumerable.Range(0, 1000).Select(s => (decimal)s).ToArray();// 手动执行GC GC.Collect();Console.ReadLine();public class GcStwMetricsCollector : EventListener {// GC关键字private const int GC_KEYWORD = 0x0000001;// 我们要关注的GC事件private const int GCSuspendEEBegin = 9;private const int GCRestartEEEnd = 3;private EventSource? _eventSource;public void Stop(){if (_eventSource == null)return;DisableEvents(_eventSource);}protected override void OnEventSourceCreated(EventSource eventSource){_eventSource = eventSource;// GC 事件在 Microsoft-Windows-DotNETRuntime 名称空间下 if (eventSource.Name.Equals("Microsoft-Windows-DotNETRuntime")){// 启用事件，事件级别为Informational， 只监听GC事件EnableEvents(eventSource, EventLevel.Informational, (EventKeywords) (GC_KEYWORD));}}private long _currentStwStartTime = 0;protected override void OnEventWritten(EventWrittenEventArgs e){switch (e.EventId){// 冻结托管线程开始，记录当前时间case GCSuspendEEBegin:_currentStwStartTime = e.TimeStamp.Ticks;break;// 恢复托管线程结束，计算当前时间与冻结托管线程开始时间的差值case GCRestartEEEnd:if (_currentStwStartTime > 0){var ms = TimeSpan.FromTicks(e.TimeStamp.Ticks - _currentStwStartTime).TotalMilliseconds;_currentStwStartTime = 0;// 输出结果Console.WriteLine($"STW: {ms}ms");}break;}}}
折叠
运行结果：
STW: 0.2568ms
至于GC事件对应的枚举值，大家可以在我上文中给出的文档中找到。
.NET7新API
在实现这个需求时，我注意到.NET7有一个新的issue，直接提供了一个API，让我们可以获取到总的GC STW Time，我把重点的信息摘抄和翻译了一下。
背景和动机
今天我们已经在GetGCMemoryInfo 公开了获取GC处理时间和暂停时间的百分比值的API。
具体来说是通过GCMemoryInfo的PauseTimePercentage字段。
这个很有用，但是如果我只想要一个分子(即：程序运行以来总的GC暂停时间)。现在没有办法获取到。
API 提案
我建议在System.GC上添加一个下面这样的API：
TimeSpan System.GC.GetTotalPauseDuration()它会返回GC总的暂停时间。
API 使用
TimeSpan start = System.GC.GetTotalPauseDuration();// ... Perform some work ...TimeSpan end= System.GC.GetTotalPauseDuration();Console.WriteLine(end - start + " was spent pausing in GC");
我看到这个API已经和最新的.NET7预览版一起发布，我们下载最新的.NET7 SDK，然后把项目改成.NET7，来试试这个API，代码如下所示：
using System.Diagnostics.Tracing;// 开启GC事件监听 var gc = new GcStwMetricsCollector();// 创建一些对象 var array = Enumerable.Range(0, 1000).Select(s => (decimal)s).ToArray();// 手动执行GC GC.Collect();Console.WriteLine($"API STW:{GC.GetTotalPauseDuration().TotalMilliseconds}ms");Console.ReadLine();// 省略上文中一样的代码
运行结果：
API STW: 0.223ms
Event STW: 0.296ms
API统计的应该会更加准确，我们通过事件来获取多多少少有一点额外的开销，不过误差在可接受的范围内。
总结
上文中提到了两种方式来获取.NET GC STW Time，我们只需要稍加改造，就可以将STW监控的功能加入APM中，如下图表就是本地测试时采集的一些数据。
当然通过EventListener还可以实现更多的APM信息的采集，大家有兴趣也可以研究看看。
本文代码链接Github: https://github.com/InCerryGit/BlogCodes/tree/main/Get-GC-STW-Time
