SOS扩展系列---利用SOS计算变量生存期
下面这个程序有一个bug,试试看你能不能抓住它。
Test.cs (编译成 DelegateExample.exe):
using System; using System.Threading; using System.Runtime.InteropServices; class Test { delegate uint ThreadProc (IntPtr arg); private uint m; public Test (uint n) { m = n; } uint Reflect (IntPtr arg) { Console.WriteLine (m); return m; } static void Main () { Test t = new Test (1); ThreadProc tp = new ThreadProc (t.Reflect); NewThread (tp); Thread.Sleep (1000); } [DllImport("UsingCallback")] static extern void NewThread (ThreadProc proc); }
UsingCallback.cpp (编译成UsingCallback.dll):
_stdcall void NewThread (LPTHREAD_START_ROUTINE cb) { DWORD id = 0; CreateThread (NULL, 0, cb, NULL, 0,&id); }
是的,问题是:在cs文件中,托管代码将委托对象传递给非托管代码,非托管代码将创建一个新线程来调用委托。由于非托管代码无法告诉CLR它计划如何使用该对象,因此从CLR的角度来看,在“NewThread(tp);”行后面没有委托对象的活动根。因此,即使新线程尚未启动,该对象也有资格在调用后被垃圾回收(GC)。因此,在非托管代码调用委托并导致未指定的失败之前,委托有可能成为垃圾桶。一个修复方法是添加GC.KeepAlive公司在主返回之前:
Test t = new Test (1); ThreadProc tp = new ThreadProc (t.Reflect); NewThread (tp); Thread.Sleep (1000); GC.KeepAlive (tp);
我教你怎么用SOS.dll检查CLR用于确定变量生存期的内部数据结构。当JIT编译代码时,它为每个方法生成这样的变量有效性信息(GC info),并将其与方法的机器代码一起保存。当GC发生时,它将检查堆栈中每个方法的GC信息,以找出哪个变量是活动的,并将活动变量用作对象根。GC信息是高度压缩的,但是SOS.dll有“!GCInfo“命令破解它并以人类可读的方式显示它。这种方法只适用于汇编级别,所以如果您对汇编语言不感兴趣,请停止阅读。
我编译的Test.cs上面用visualstudio进行了“调试”构建,并在Windbg下启动了程序。在Main方法被JITted之后,我可以使用“!SOS.u“命令:
0:000> !u 02f00058 Will print '>>> ' at address: 02f00058 Normal JIT generated code [DEFAULT] Void Test.Main() Begin 02f00058, size 60 >>> 02f00058 55 push ebp 02f00059 8bec mov ebp,esp 02f0005b 83ec08 sub esp,0x8 02f0005e 57 push edi 02f0005f 56 push esi 02f00060 53 push ebx 02f00061 33ff xor edi,edi 02f00063 33db xor ebx,ebx 02f00065 b9e850ad00 mov ecx,0xad50e8 (MT: Test) 02f0006a e8a91fbcfd call 00ac2018 (JitHelp: nc) 02f0006f 8bf0 mov esi,eax 02f00071 8bce mov ecx,esi 02f00073 ba01000000 mov edx,0x1 02f00078 ff152051ad00 call dword ptr [00ad5120] (Test..ctor) 02f0007e 8bfe mov edi,esi 02f00080 b9c451ad00 mov ecx,0xad51c4 (MT: Test/ThreadProc) 02f00085 e88e1fbcfd call 00ac2018 (JitHelp: nc) 02f0008a 8bf0 mov esi,eax 02f0008c 689350ad00 push 0xad5093 02f00091 8bd7 mov edx,edi 02f00093 8bce mov ecx,esi 02f00095 ff152452ad00 call dword ptr [00ad5224] (Test/ThreadProc..ctor) 02f0009b 8bde mov ebx,esi 02f0009d 8bcb mov ecx,ebx 02f0009f ff152c51ad00 call dword ptr [00ad512c] (Test.NewThread) 02f000a5 b9e8030000 mov ecx,0x3e8 02f000aa ff155084bb79 call dword ptr [mscorlib_79990000+0x228450 (79bb8450)] (System.Threading.Thread.Sleep) 02f000b0 90 nop 02f000b1 5b pop ebx 02f000b2 5e pop esi 02f000b3 5f pop edi 02f000b4 8be5 mov esp,ebp 02f000b6 5d pop ebp 02f000b7 c3 ret
SOS的“!u”与Windbg的“u”类似,但它显示的数据更多,因为托管代码是可自我描述的。例如,对于那些间接调用,如果目标是托管函数,“!u“可以告诉我们函数名。
为了检查它的GC信息,我们需要首先获取该方法的MethodDesc(方法描述符,CLR的数据结构来保存关于一个方法的所有信息)。我们可以用“!ip2md“要从方法中的任何指令指针中找到方法desc:
0:000> !ip2md 02f00058 MethodDesc: 0x00ad50a8 Jitted by normal JIT Method Name : [DEFAULT] Void Test.Main() MethodTable ad50e8 Module: 151ad0 mdToken: 06000003 (D:\projects\DelegateExample\bin\Debug\DelegateExample.exe) Flags : 10 Method VA : 02f00058
此命令显示有关该方法的一些重要信息。为了检查GC信息,我们只需要将MethodDesc指针本身传递到“!GCInfo“:
0:000> !gcinfo 0x00ad50a8 Normal JIT generated code Method info block: method size = 0060 prolog size = 9 epilog size = 7 epilog count = 1 epilog end = yes saved reg. mask = 000F ebp frame = yes fully interruptible=yes double align = no security check = no exception handlers = no local alloc = no edit & continue = yes varargs = no argument count = 0 stack frame size = 2 untracked count = 0 var ptr tab count = 0 epilog at 0059 60 E5 C0 45 | Pointer table: F0 7B | 000B reg EDI becoming live 5A | 000D reg EBX becoming live F0 42 | 0017 reg EAX becoming live 72 | 0019 reg ESI becoming live 4A | 001B reg ECX becoming live F0 03 | 0026 reg EAX becoming dead 08 | 0026 reg ECX becoming dead F0 44 | 0032 reg EAX becoming live 30 | 0032 reg ESI becoming dead 72 | 0034 reg ESI becoming live 57 | 003B reg EDX becoming live 4A | 003D reg ECX becoming live 06 | 0043 reg EAX becoming dead 08 | 0043 reg ECX becoming dead 10 | 0043 reg EDX becoming dead 4C | 0047 reg ECX becoming live 0E | 004D reg ECX becoming dead 30 | 004D reg ESI becoming dead F1 1B | 0060 reg EBX becoming dead 38 | 0060 reg EDI becoming dead FF |
这个命令的输出有两个部分,第一部分是method info block,它包含一些关于JITted代码的基本信息,比如方法的大小,prolog的大小等等;第二部分是指针表,我将花大部分时间在上面。指针表描述了方法内每个GC引用的生存期。它有3列,第一列是字节编码,我们不需要关心它;第二列是JITted代码中的偏移量。E、 g,这个方法的代码从02f00058开始,所以000B表示在02f00058+B=2F00063处的指令,“xor ebx,ebx”;第三列告诉我们该指令的GC指针的生存期更改。E、 g,“000B reg EDI being live”表示从2F00063开始,寄存器EDI是一个活根;类似地,我们可以看到EDI在偏移量60处变死,方法结束(0060 reg EDI变死)。所以无论使用EDI存储什么变量,它的生命周期都是从方法的开始到结束。为了理解指针表,最好将表与JITted代码交织在一起。SOS有“!u-gcinfo“来完成这项工作;我必须手动将它们放在一起,并与源代码一起显示:
02f00058 55 push ebp 02f00059 8bec mov ebp,esp 02f0005b 83ec08 sub esp,0x8 02f0005e 57 push edi 02f0005f 56 push esi 02f00060 53 push ebx 02f00061 33ff xor edi,edi GCInfo: 000B reg EDI becoming live 02f00063 33db xor ebx,ebx GCInfo: 000D reg EBX becoming live Test t = new Test (1); 02f00065 b9e850ad00 mov ecx,0xad50e8 (MT: Test) 02f0006a e8a91fbcfd call 00ac2018 (JitHelp: nc) GCInfo: 0017 reg EAX becoming live 02f0006f 8bf0 mov esi,eax GCInfo: 0019 reg ESI becoming live 02f00071 8bce mov ecx,esi GCInfo: 001B reg ECX becoming live 02f00073 ba01000000 mov edx,0x1 02f00078 ff152051ad00 call dword ptr [00ad5120] (Test..ctor) GCInfo: 0026 reg EAX becoming dead GCInfo: 0026 reg ECX becoming dead 02f0007e 8bfe mov edi,esi ThreadProc tp = new ThreadProc (t.Reflect); 02f00080 b9c451ad00 mov ecx,0xad51c4 (MT: Test/ThreadProc) 02f00085 e88e1fbcfd call 00ac2018 (JitHelp: nc) GCInfo: 0032 reg EAX becoming live GCInfo: 0032 reg ESI becoming dead 02f0008a 8bf0 mov esi,eax GCInfo: 0034 reg ESI becoming live 02f0008c 689350ad00 push 0xad5093 02f00091 8bd7 mov edx,edi GCInfo: 003B reg EDX becoming live 02f00093 8bce mov ecx,esi GCInfo: 003D reg ECX becoming live 02f00095 ff152452ad00 call dword ptr [00ad5224] (Test/ThreadProc..ctor) GCInfo: 0043 reg EAX becoming dead GCInfo: 0043 reg ECX becoming dead GCInfo: 0043 reg EDX becoming dead NewThread (tp); 02f0009b 8bde mov ebx,esi 02f0009d 8bcb mov ecx,ebx GCInfo: 0047 reg ECX becoming live 02f0009f ff152c51ad00 call dword ptr [00ad512c] (Test.NewThread) GCInfo: 004D reg ECX becoming dead GCInfo: 004D reg ESI becoming dead Thread.Sleep (1000); 02f000a5 b9e8030000 mov ecx,0x3e8 02f000aa ff155084bb79 call dword ptr [mscorlib_79990000+0x228450 (79bb8450)] (System.Threading.Thread.Sleep) 02f000b0 90 nop 02f000b1 5b pop ebx 02f000b2 5e pop esi 02f000b3 5f pop edi 02f000b4 8be5 mov esp,ebp 02f000b6 5d pop ebp 02f000b7 c3 ret GCInfo: 0060 reg EBX becoming dead GCInfo: 0060 reg EDI becoming dead
假设一个线程在另一个线程执行代码02f0009d时触发GC,从表中我们知道,此时,寄存器ESI、EBX和EDI将作为活动根向GC报告。通过一些反汇编,我们可以看到此时ESI和EBX都包含对委托tp的引用,EDI是变量t。EBX和EDI在函数结束之前都保持活动状态可能会让您感到惊讶。这意味着变量t和tp对于整个函数实际上是活的,所以代码没有bug?!
棘手的一点是,一个变量一旦不再使用就有资格死。然而,这取决于JIT来决定它是否真的想报告这个变量是死的。事实上,对于可调试代码,JIT将每个变量的生存期延长到函数的末尾。
为了证明示例中确实存在早熟的GC bug,我将其编译为“Release”build,并重复了上述所有步骤:
0:000> !u 02df0058 Loaded Son of Strike data table version 5 from "C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll" Will print '>>> ' at address: 02df0058 Normal JIT generated code [DEFAULT] Void Test.Main() Begin 02df0058, size 46 >>> 02df0058 57 push edi 02df0059 56 push esi 02df005a b9e850ad00 mov ecx,0xad50e8 (MT: Test) 02df005f e8b41fcdfd call 00ac2018 (JitHelp: nc) 02df0064 8bf0 mov esi,eax 02df0066 c7460401000000 mov dword ptr [esi+0x4],0x1 02df006d b9bc51ad00 mov ecx,0xad51bc (MT: Test/ThreadProc) 02df0072 e8a11fcdfd call 00ac2018 (JitHelp: nc) 02df0077 8bf8 mov edi,eax 02df0079 689350ad00 push 0xad5093 02df007e 8bd6 mov edx,esi 02df0080 8bcf mov ecx,edi 02df0082 ff151c52ad00 call dword ptr [00ad521c] (Test/ThreadProc..ctor) 02df0088 8bcf mov ecx,edi 02df008a ff152c51ad00 call dword ptr [00ad512c] (Test.NewThread) 02df0090 b9e8030000 mov ecx,0x3e8 02df0095 ff155084bb79 call dword ptr [mscorlib_79990000+0x228450 (79bb8450)] (System.Threading.Thread.Sleep) 02df009b 5e pop esi 02df009c 5f pop edi 02df009d c3 ret 0:000> !ip2md 02df0058 MethodDesc: 0x00ad50a8 Jitted by normal JIT Method Name : [DEFAULT] Void Test.Main() MethodTable ad50e8 Module: 151ad0 mdToken: 06000003 (D:\projects\DelegateExample\bin\Release\DelegateExample.exe) Flags : 10 Method VA : 02df0058 0:000> !gcinfo 0x00ad50a8 Normal JIT generated code Method info block: method size = 0046 prolog size = 2 epilog size = 3 epilog count = 1 epilog end = yes saved reg. mask = 0003 ebp frame = no fully interruptible=no double align = no security check = no exception handlers = no local alloc = no edit & continue = no varargs = no argument count = 0 stack frame size = 0 untracked count = 0 var ptr tab count = 0 epilog at 0043 46 21 | Pointer table: A9 | 001F call 0 [ ESI ] 07 | 0026 push CB | 0030 call 1 [ EDI ] FF |
以下是混合源代码、本机代码和指针表:
02df0058 57 push edi 02df0059 56 push esi Test t = new Test (1); 02df005a b9e850ad00 mov ecx,0xad50e8 (MT: Test) 02df005f e8b41fcdfd call 00ac2018 (JitHelp: nc) 02df0064 8bf0 mov esi,eax 02df0066 c7460401000000 mov dword ptr [esi+0x4],0x1 ThreadProc tp = new ThreadProc (t.Reflect); 02df006d b9bc51ad00 mov ecx,0xad51bc (MT: Test/ThreadProc) 02df0072 e8a11fcdfd call 00ac2018 (JitHelp: nc) GCInfo: 001F call 0 [ ESI ] 02df0077 8bf8 mov edi,eax 02df0079 689350ad00 push 0xad5093 GCInfo: 0026 push 02df007e 8bd6 mov edx,esi 02df0080 8bcf mov ecx,edi 02df0082 ff151c52ad00 call dword ptr [00ad521c] (Test/ThreadProc..ctor) GCInfo: 0030 call 1 [ EDI ] EM>NewThread (tp); 02df0088 8bcf mov ecx,edi 02df008a ff152c51ad00 call dword ptr [00ad512c] (Test.NewThread) Thread.Sleep (1000); 02df0090 b9e8030000 mov ecx,0x3e8 02df0095 ff155084bb79 call dword ptr [mscorlib_79990000+0x228450 (79bb8450)] (System.Threading.Thread.Sleep) 02df009b 5e pop esi 02df009c 5f pop edi 02df009d c3 ret
在发布版本中,JIIted代码更小,GC-info中的指针表更小。我需要解释一下这个指针表中的一些新语法:“call 0[ESI]”表示该方法调用一个参数为0的函数,而ESI此时是一个活变量;“push”只表示堆栈的变化,这是GC展开此帧的重要信息,但不影响指针的有效性。
这个新指针表的一个有趣之处是,它只在方法调用其他方法时报告GC引用。如果GC发生在其他地方呢?例如,在02df0079行,EDI包含object tp,ESI包含object t,如果在线程执行02df0079时发生GC,但GCInfo没有报告这两个变量,那么它们会被收集吗?答案是GC不会在那个地方发生。在method info块中有一个重要字段叫做“完全可中断”。在调试版本中,方法的此字段为true,但在发布版本中,该字段为false。方法是完全可中断的意味着如果线程正在执行这个方法,GC可以在任何时候停止线程(并执行收集)。如果一个方法不是完全可中断的,那么如果一个线程正在执行这个方法,GC就不能从任意点开始。它必须等到线程从调用返回时(例如,从ThreadProc的构造函数返回Main)或方法调用另一个允许GC发生的方法时(通过PInvoke调用非托管代码总是允许GC发生)。这就是为什么我们只需要在电话中报告变量。出于性能原因,这些琐碎的方法测试。主在发布版本中通常是不完全可中断的。
有了所有的知识,现在我们知道如果GC发生在线程刚刚从指令02df0072的“new ThreadProc”调用返回时,GC知道ESI(变量t)是一个活动根;如果GC发生在线程刚刚从02df0082对ThreadProc的构造函数的调用返回时,GC知道EDI(变量tp)是一个活动根。这次没有报告变量t(但是它被对象tp保存)。但是,如果当线程在02df008a从NewThread调用返回时发生GC,则不会报告t和tp,以便GC可以收集它们。如果新线程还没有启动,那么它在使用对象时会遇到问题。
所以下一次如果你怀疑可能有一些过早的GC错误,你可以试试“!SOS.GCInfo“看看CLR是如何看待GC对象的生存期的。