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);
这类bug的一个恼人之处是GC是不确定的,程序99%的时间都可以正常工作,但只会在压力下崩溃。另一个让问题很难找到的是,它不是很直观地看来源。您可能知道这样一个理论:当一个变量不再使用时,它将不会被报告为一个活根;但是要弄清楚哪个变量在哪一点上是死的,而且无法验证CLR是否同意您的分析。

我教你怎么用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对象的生存期的。

posted on 2020-08-24 08:00  活着的虫子  阅读(310)  评论(0编辑  收藏  举报

导航