• windbg的时间旅行实现对 C# 程序的终极调试！

    一：什么是时间旅行

    简而言之就是把程序的执行流拍成vlog，这样就可以对 vlog 快进或者倒退，还可以分享给别人做进一步的分析，是不是想都不敢想。

    很开心的是 windbg preview 版本中已经实现了，叫做 时间旅行调试 TTD，相比传统的 静态分析 不知道好多少倍。

    为了能提起大家兴趣，我就举二个例子吧。

    二：二个有趣的例子

    1. 查看程序都触发了第几代垃圾回收

    为了方便说明，我就用诱导GC手工触发，然后再观察都触发了哪一代的 GC ，参考代码如下：

    1.         static void Main(string[] args)
    2.         {
    3.             List<string> list = new List<string>();
    4.  
    5.             //1. 第一次触发GC
    6.             GC.Collect();
    7.  
    8.             Console.WriteLine("触发full gc");
    9.  
    10.             //2. 第二次触发GC
    11.             GC.Collect(0);
    12.  
    13.             Console.WriteLine("触发 0 代 gc");
    14.  
    15.             //3.第二次触发GC
    16.             GC.Collect(1);
    17.  
    18.             Console.WriteLine("触发 1 代 gc");
    19.         }
    20.

    接下来用 windbg 的 launch executeable (advanced) 来附加程序，勾选 Record，然后在弹框中将 vlog 保存到指定目录，最后点击 Record 就可以啦！

    运行完后，windbg 会自动加载我的 D:\test\ConsoleApp104.run 的 vlog 文件，因为 gc 触发的底层函数是coreclr!WKS::GCHeap::GarbageCollectGeneration ，所以我们用 bp 给它下一个断点，运行多次 g 命令。

    1. 0:000> bp coreclr!WKS::GCHeap::GarbageCollectGeneration
    2. Bp expression 'coreclr!WKS::GCHeap::GarbageCollectGeneration' could not be resolved, adding deferred bp
    3. 0:000> g
    4. Time Travel Position: 3079F:63E
    5. eax=00000001 ebx=00000002 ecx=00000002 edx=00000008 esi=00000002 edi=00000002
    6. eip=02fc4256 esp=0057f204 ebp=0057f214 iopl=0         nv up ei pl nz na po nc
    7. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000202
    8. coreclr!WKS::GCHeap::GarbageCollectGeneration:
    9. 02fc4256 55              push    ebp
    10. 0:000> g
    11. Time Travel Position: 34661:AF
    12. eax=00000001 ebx=00000002 ecx=00000000 edx=00000008 esi=00000000 edi=00000002
    13. eip=02fc4256 esp=0057f1f8 ebp=0057f208 iopl=0         nv up ei pl nz na po nc
    14. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000202
    15. coreclr!WKS::GCHeap::GarbageCollectGeneration:
    16. 02fc4256 55              push    ebp
    17. 0:000> g
    18. Breakpoint 0 hit
    19. Time Travel Position: 346A5:2CD
    20. eax=00000001 ebx=00000002 ecx=00000001 edx=00000008 esi=00000001 edi=00000002
    21. eip=02fc4256 esp=0057f1f8 ebp=0057f208 iopl=0         nv up ei pl nz na po nc
    22. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000202
    23. coreclr!WKS::GCHeap::GarbageCollectGeneration:
    24. 02fc4256 55              push    ebp
    25.

    从输出中可以很清楚的看到，命中了三次 GarbageCollectGeneration 回收，而且从上面的 ecx 寄存器看依次是 2,0,1，对应着 gc 的2代回收，0代回收， 1代回收， 这比只有一个静态的 dump 是不是有优势的多，要知道我这里的 ConsoleApp101.run 文件是可以分发给别人分析的哦。

    2. 查看新生成的线程曾今都执行了什么代码

    这个例子源自朋友遇到的一个问题，他的程序跑着跑着，发现 ThreadPool 中有400多待命的工作线程，线程栈大概如下：

    1. 0:011> k
    2.  # ChildEBP RetAddr      
    3. 00 0564fc6c 7531f0ca     ntdll!NtRemoveIoCompletion+0xc
    4. 01 0564fc6c 78480b69     KERNELBASE!GetQueuedCompletionStatus+0x2a
    5. 02 0564fcb8 7847d92b     coreclr!CLRLifoSemaphore::WaitForSignal+0x29 [d:\a\_work\1\s\src\vm\synch.cpp @ 654] 
    6. 03 0564fd08 7847cf04     coreclr!CLRLifoSemaphore::Wait+0x13b [d:\a\_work\1\s\src\vm\synch.cpp @ 897] 
    7. 04 0564fdd4 783f2910     coreclr!ThreadpoolMgr::WorkerThreadStart+0x234 [d:\a\_work\1\s\src\vm\win32threadpool.cpp @ 2121] 
    8. 05 0564ff70 7703fa29     coreclr!Thread::intermediateThreadProc+0x50 [d:\a\_work\1\s\src\vm\threads.cpp @ 2110] 
    9. 06 0564ff80 772175f4     KERNEL32!BaseThreadInitThunk+0x19
    10. 07 0564ffdc 772175c4     ntdll!__RtlUserThreadStart+0x2f
    11. 08 0564ffec 00000000     ntdll!_RtlUserThreadStart+0x1b
    12.

    因为给我的是 静态dump，所以我无法寻找 11号线程 曾今执行了什么托管代码，因为时间不能倒流，但现在有了 TTD，真的可以让时间倒流啦。。。太有意思了，哈哈，既然能倒流，那就一定有办法找到破绽。

    为了方便讲解，写一个简单例子。

    1.         static void Main(string[] args)
    2.         {
    3.             Task.Factory.StartNew(() =>
    4.             {
    5.                 Console.WriteLine("我是 task 线程");
    6.             });
    7.  
    8.             Console.ReadLine();
    9.         }
    10.

    接下来我们一起探究下最后生成的 Thread WorkThread 曾今都执行了什么？深挖思路大概是这样的。

    先将进度条拉到底，然后用 !bpmd System_Private_CoreLib System.Threading.Tasks.Task.InnerInvoke 下一个断点，最后将时间倒流，看谁命中了这个 task。

    1. 0:000> g
    2. TTD: End of trace reached.
    3. (4f20.4d0c): Break instruction exception - code 80000003 (first/second chance not available)
    4. Time Travel Position: 36F51:0
    5. eax=00070053 ebx=00000000 ecx=8a60f857 edx=77237170 esi=7845e6c0 edi=00000000
    6. eip=771a7000 esp=0602fe90 ebp=0602ff70 iopl=0         nv up ei pl zr na pe nc
    7. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
    8. 771a7000 ea09701a773300  jmp     0033:771A7009
    9.  
    10. 0:009> !bpmd System_Private_CoreLib System.Threading.Tasks.Task.InnerInvoke
    11. MethodDesc = 06A29704
    12. Setting breakpoint: bp 05A915C7 [System.Threading.Tasks.Task.InnerInvoke()]
    13. Adding pending breakpoints...
    14.  
    15. 0:009> g-
    16. Breakpoint 1 hit
    17. Time Travel Position: 32DF4:AC
    18. eax=05a915c0 ebx=00000000 ecx=0349a864 edx=0349a864 esi=0349a864 edi=0349a7c8
    19. eip=05a915c7 esp=066afa14 ebp=066afa1c iopl=0         nv up ei pl zr na pe nc
    20. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
    21. System_Private_CoreLib!System.Threading.Tasks.Task.InnerInvoke()$##6002185+0x7:
    22. 05a915c7 8b7e04          mov     edi,dword ptr [esi+4] ds:002b:0349a868=0349a800
    23.  
    24. 0:008> !clrstack 
    25. OS Thread Id: 0x44a8 (8)
    26. Child SP       IP Call Site
    27. 066AFA14 05a915c7 System.Threading.Tasks.Task.InnerInvoke() [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2437]
    28. 066AFA24 05a915bb System.Threading.Tasks.Task+c.<.cctor>b__274_0(System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2427]
    29. 066AFA2C 05a91567 System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 289]
    30. 066AFA5C 05a912d1 System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2389]
    31. 066AFABC 05a911d7 
    32. 066AFACC 05a9118b System.Threading.Tasks.Task.ExecuteFromThreadPool(System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2312]
    33. 066AFAD0 05a90e58 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 663]
    34. 066AFB1C 05a90c6f 
    35. 066AFD10 784fa0ef [DebuggerU2MCatchHandlerFrame: 066afd10] 
    36.

    熟悉 Task 的朋友应该知道: System.Threading.Tasks.Task.InnerInvoke 的下一步就是执行我的回调函数，而此时 回调函数 还没有被 JIT 编译，这时候我们可以在 bp clrjit!CILJit::compileMethod 中去拦截 JIT 对此方法的编译，然后从 compileMethod 中提取 mt。

    1. 0:008> bp clrjit!CILJit::compileMethod
    2. 0:008> g
    3. Breakpoint 1 hit
    4. Time Travel Position: 32E36:C18
    5. eax=7933ad50 ebx=066af5c8 ecx=792c8770 edx=066af5c8 esi=7932d164 edi=00cbbf90
    6. eip=792c8770 esp=066af3ec ebp=066af44c iopl=0         nv up ei pl zr na pe nc
    7. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
    8. clrjit!CILJit::compileMethod:
    9. 792c8770 55              push    ebp
    10.  
    11. 0:008> kb
    12.  # ChildEBP RetAddr      Args to Child              
    13. 00 066af44c 78428db2     7933ad50 066af5c8 066af4f0 clrjit!CILJit::compileMethod [d:\a\_work\1\s\src\jit\ee_il_dll.cpp @ 294] 
    14. ...
    15.  
    16. 0:008> dp 066af4f0 L1
    17. 066af4f0  06a2ae04
    18.  
    19. 0:008> !dumpmd 06a2ae04
    20. Method Name:          ConsoleApp1.dll!Unknown
    21. Class:                032fa0dc
    22. MethodTable:          06a2ae14
    23. mdToken:              06000005
    24. Module:               02c5d7d0
    25. IsJitted:             no
    26. Current CodeAddr:     ffffffff
    27. Version History:
    28.   ILCodeVersion:      00000000
    29.   ReJIT ID:           0
    30.   IL Addr:            00000000
    31.      CodeAddr:           00000000  (MinOptJitted)
    32.      NativeCodeVersion:  00000000
    33.

    很奇怪的是提取的 md 目前还不能显示完全名字，不过没关系，我们继续 g ，然后再重复执行一下命令。

    1. 0:009> g
    2. TTD: End of trace reached.
    3. (4f20.4d0c): Break instruction exception - code 80000003 (first/second chance not available)
    4. Time Travel Position: 36F51:0
    5. eax=00070053 ebx=00000000 ecx=8a60f857 edx=77237170 esi=7845e6c0 edi=00000000
    6. eip=771a7000 esp=0602fe90 ebp=0602ff70 iopl=0         nv up ei pl zr na pe nc
    7. cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
    8. 771a7000 ea09701a773300  jmp     0033:771A7009
    9. 0:009> !dumpmd 06a2ae04
    10. Method Name:          ConsoleApp1.Program+<>c.<Main>b__0_0()
    11. Class:                032fa0dc
    12. MethodTable:          06a2ae14
    13. mdToken:              06000005
    14. Module:               02c5d7d0
    15. IsJitted:             yes
    16. Current CodeAddr:     06133300
    17. Version History:
    18.   ILCodeVersion:      00000000
    19.   ReJIT ID:           0
    20.   IL Addr:            00000000
    21.      CodeAddr:           06133300  (MinOptJitted)
    22.      NativeCodeVersion:  00000000
    23.

    当时间线结束的时候，我们终于看到了，原来 Task 执行的是 ConsoleApp1.Program+<>c.<Main>b__0_0() 方法，那这个方法逻辑是什么呢？可以用 ILSpy 查看。

    总的来说，要复现还是挺考验基本功的。

  • 相关阅读:
    风力涡轮机损伤检测图像数据集（400多张图像，VOC标签）
    UVM RAL模型和内置seq
    LeetCode50天刷题计划（Day 25— 旋转图像（11.20-12.30）
    C#以太网简介
    STM32F4X OLED使用
    【无标题】
    1200*A. Flipping Game（前缀和）
    【大数据】Apache Hive数仓（学习笔记）
    希尔伯特变换分析及应用
    C. Make Good
  • 原文地址：https://blog.csdn.net/biyusr/article/details/125575975