登录/注册
🐳 我就是我🐳
2618
占位
1
占位
0
浏览量
占位
粉丝
占位
关注
PerfView专题 (第七篇):如何洞察触发 GC 的 C# 代码?
🐳 我就是我🐳
2022-09-19 17:25:07 2022-09-19
18
0

一:背景

上一篇我们聊到了如何用 PerfView 洞察 GC 的变化,但总感觉还缺了点什么? 对,就是要跟踪到底是什么代码触发了 GC,这对我们分析由于 GC 导致的 CPU 爆高有非常大的参考价值,在以前我都是用 WinDBG 来实现,但这玩意需要做一些侵入性操作,实战起来不是那么丝滑,虽然有可以录制功能的 TTD,所以需寻找完美的解决方案,在此可以借助一下 PerfView 。

二:如何洞察

1. 一个小案例

为了方便讲解,先上一段简单的测试代码,不断的往 List 中塞入数据,可以实现不断的 GC 触发。

namespace ConsoleApp6
{
internal class Program
{
static void Main(string[] args)
{
Task.Run(Alloc1);
Console.ReadLine();
}
static void Alloc1()
{
List<string> list = new List<string>();
var rand = new Random();
for (int i = 0; i < int.MaxValue; i++)
{
list.Add(string.Join(",", Enumerable.Range(1, 1000)));
Console.WriteLine(i);
}
}
}
}

2. WinDbg 拦截

用 windbg 拦截的话非常简单,只需要找到 CoreCLR 中触发 GC 的入口方法,然后下一个断点,再用 k 查看其线程栈即可。

0:012> bp coreclr!WKS::GCHeap::GarbageCollectGeneration
0:012> g
Breakpoint 0 hit
coreclr!WKS::GCHeap::GarbageCollectGeneration:
00007ffa`7823f8cc 48895c2408 mov qword ptr [rsp+8],rbx ss:00000000`2321f200=00000000006c49f8
0:008> k
# Child-SP RetAddr Call Site
00 00000000`2321f1f8 00007ffa`782f59db coreclr!WKS::GCHeap::GarbageCollectGeneration [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 44615]
01 00000000`2321f200 00007ffa`78337b5d coreclr!WKS::gc_heap::trigger_gc_for_alloc+0x2b [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 16846]
02 00000000`2321f230 00007ffa`782db675 coreclr!WKS::gc_heap::try_allocate_more_space+0x5c4c1 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 16977]
03 00000000`2321f290 00007ffa`78247784 coreclr!WKS::gc_heap::allocate_more_space+0x31 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 17447]
04 (Inline Function) --------`-------- coreclr!WKS::gc_heap::allocate+0x58 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 17478]
05 00000000`2321f2c0 00007ffa`781d9768 coreclr!WKS::GCHeap::Alloc+0x84 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 43676]
06 (Inline Function) --------`-------- coreclr!Alloc+0x125 [D:\a\_work\1\s\src\coreclr\vm\gchelpers.cpp @ 228]
07 00000000`2321f2f0 00007ffa`782cc0d9 coreclr!AllocateString+0x19c [D:\a\_work\1\s\src\coreclr\vm\gchelpers.cpp @ 861]
08 00000000`2321f390 00007ffa`18782d10 coreclr!FramedAllocateString+0x79 [D:\a\_work\1\s\src\coreclr\vm\jithelpers.cpp @ 2429]
09 00000000`2321f4e0 00007ffa`1878687d System_Private_CoreLib!System.Number.Int32ToDecStr+0xb0
0a 00000000`2321f530 00007ffa`1878668a System_Private_CoreLib!System.String.JoinCore<int>+0x1bd
0b 00000000`2321f7e0 00007ffa`1877bdcc System_Private_CoreLib!System.String.Join<int>+0x2a
0c 00000000`2321f820 00007ffa`776d2d0e ConsoleApp10!ConsoleApp10.Program.Alloc1+0xbc [D:\net6\ConsoleApp1\ConsoleApp10\Program.cs @ 24]
0d 00000000`2321f8a0 00007ffa`776d7716 System_Private_CoreLib!System.Threading.Tasks.Task.InnerInvoke+0x1e
0e 00000000`2321f8d0 00007ffa`776bd7f5 System_Private_CoreLib!System.Threading.Tasks.Task.<>c.<.cctor>b__272_0+0x16
0f 00000000`2321f900 00007ffa`776d2a38 System_Private_CoreLib!System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop+0x35
10 00000000`2321f950 00007ffa`776d2943 System_Private_CoreLib!System.Threading.Tasks.Task.ExecuteWithThreadLocal+0x98
11 00000000`2321f9f0 00007ffa`776c6213 System_Private_CoreLib!System.Threading.Tasks.Task.ExecuteEntryUnsafe+0x53
12 00000000`2321fa30 00007ffa`776cdd8a System_Private_CoreLib!System.Threading.ThreadPoolWorkQueue.Dispatch+0x263
13 00000000`2321fad0 00007ffa`776b278f System_Private_CoreLib!System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart+0x14a
14 00000000`2321fbe0 00007ffa`7830a853 System_Private_CoreLib!System.Threading.Thread.StartCallback+0x3f
15 00000000`2321fc20 00007ffa`781fd43c coreclr!CallDescrWorkerInternal+0x83
16 00000000`2321fc60 00007ffa`782ebf93 coreclr!DispatchCallSimple+0x80 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 220]
17 00000000`2321fcf0 00007ffa`78258695 coreclr!ThreadNative::KickOffThread_Worker+0x63 [D:\a\_work\1\s\src\coreclr\vm\comsynchronizable.cpp @ 158]
18 (Inline Function) --------`-------- coreclr!ManagedThreadBase_DispatchInner+0xd [D:\a\_work\1\s\src\coreclr\vm\threads.cpp @ 7321]
19 00000000`2321fd50 00007ffa`7825859a coreclr!ManagedThreadBase_DispatchMiddle+0x85 [D:\a\_work\1\s\src\coreclr\vm\threads.cpp @ 7365]
1a 00000000`2321fe30 00007ffa`782583b9 coreclr!ManagedThreadBase_DispatchOuter+0xae [D:\a\_work\1\s\src\coreclr\vm\threads.cpp @ 7524]
1b (Inline Function) --------`-------- coreclr!ManagedThreadBase_FullTransition+0x2d [D:\a\_work\1\s\src\coreclr\vm\threads.cpp @ 7569]
1c (Inline Function) --------`-------- coreclr!ManagedThreadBase::KickOff+0x2d [D:\a\_work\1\s\src\coreclr\vm\threads.cpp @ 7604]
1d 00000000`2321fed0 00007ffa`e9e47034 coreclr!ThreadNative::KickOffThread+0x79 [D:\a\_work\1\s\src\coreclr\vm\comsynchronizable.cpp @ 230]
1e 00000000`2321ff30 00007ffa`e9f9d0d1 KERNEL32!BaseThreadInitThunk+0x14
1f 00000000`2321ff60 00000000`00000000 ntdll!RtlUserThreadStart+0x21

从输出中可以看到,当前触发的GC的操作是由于 ConsoleApp10!ConsoleApp10.Program.Alloc1+0xbc 方法所致,原因是由于0代阈值用完,但这种调试 CoreCLR 源码的方式终究还是侵入性较大,那有没有自动帮我收集分配 线程调用栈 的工具呢? 这就需要借助 PerfView 啦。

3. PerfView 拦截

Windows 系统内置强大的事件跟踪机制(ETW)再次显示出了威力,我们可以用 PerfView 去拦截 GC 的触发事件,并同时记录此时事件触发的调用栈,而且对应用程序的开销非常小。

接下来我们在 Provider Browser 对话框中选择 GCKeyword 选项,

然后再配上一个记录调用栈参数 @StacksEnabled=true, 最后的结果就是:

Microsoft-Windows-DotNETRuntime:GCKeyword:Always:@StacksEnabled=true

配置好之后就可以 Start Collection 了,收集好之后,我们点击面板上的 Events 项,然后输出 GC 关键词,寻找 GC 相关的事件,这里我们看下 GC/Start 事件,如下图所示:

从截图看,非常舒服,清晰的记录着每一个 GC 的详细情况。

HasStack="True" ThreadID="12,912" ProcessorNumber="3" Count="67" Reason="AllocSmall" Depth="0" Type="NonConcurrentGC" ClrInstanceID="8" ClientSequenceNumber="0"

接下来在 Time MSec 列上点击右键选择 Open Any Stacks 打开触发这个 GC 的调用栈代码。

从图中可以非常清晰的看到,Alloc1() 方法触发了 GC 并清晰记录 ETW 事件的全过程,真是太强大,太令人兴奋了。

暂无评论