记一次 .NET某机械臂上位系统 卡死分析

名字容易忘记

一：背景

1. 讲故事

前些天有位朋友找到我，说他们的程序会偶发性的卡死一段时间，然后又好了，让我帮忙看下怎么回事？窗体类的程序解决起来相对来说比较简单，让朋友用procdump自动抓一个卡死时的dump，拿到dump之后，上 windbg 说话。
二：WinDbg 分析

1. 主线程在做什么

要想看主线程在做什么，很显然用 k 命令观察非托管栈即可。

1. 0:000> k
2. # Child-SP          RetAddr               Call Site
3. 00 000000ef`11d1cb70 00007ffc`e65ddc4a     ntdll!RtlSetLastWin32Error+0x38
4. 01 000000ef`11d1cbc0 00007ffc`e660e1a4     clr!JIT_RareDisableHelperWorker+0xca
5. 02 000000ef`11d1cd00 00007ffc`b5c4ea25     clr!JIT_RareDisableHelper+0x14
6. 03 000000ef`11d1cd40 00007ffc`b5c41d35     System_Drawing_ni+0x6ea25
7. 04 000000ef`11d1ce00 00007ffc`87948876     System_Drawing_ni!System.Drawing.StringFormat..ctor+0x15
8. ....
9. 10 000000ef`11d1d8b0 00007ffc`881fc86f     xxx!xxx.AutoResizeColumns+0x106
10. ...

复制代码

从卦中数据看，托管的栈顶上有一个 RtlSetLastWin32Error 函数，看样子 JIT_RareDisableHelperWorker 方法中某一个函数返回错误码了，那这个错误码是多少呢？要知道这个答案，先要知道它的签名是什么样的，参考链接： https://source.winehq.org/WineAPI/RtlSetLastWin32Error.html

1. void RtlSetLastWin32Error
2. (
3.     DWORD err
4. )

复制代码

从签名可以看到，这个 err 是一个 int ，接下来观察 RtlSetLastWin32Error 方法的 rcx 寄存器，有没有存到 线程栈上，如果有的话直接提取即可。

1. 0:000> uf ntdll!RtlSetLastWin32Error
2. ntdll!RtlSetLastWin32Error:
3. 00007ffd`01a00780 894c2408        mov     dword ptr [rsp+8],ecx
4. 00007ffd`01a00784 4883ec48        sub     rsp,48h
5. 00007ffd`01a00788 488b05813d1300  mov     rax,qword ptr [ntdll!_security_cookie (00007ffd`01b34510)]
6. 00007ffd`01a0078f 4833c4          xor     rax,rsp
7. ....
9. 0:000> k
10. # Child-SP          RetAddr               Call Site
11. 00 000000ef`11d1cb70 00007ffc`e65ddc4a     ntdll!RtlSetLastWin32Error+0x38
12. 01 000000ef`11d1cbc0 00007ffc`e660e1a4     clr!JIT_RareDisableHelperWorker+0xca
14. 0:000> dd 000000ef`11d1cbc0 L1
15. 000000ef`11d1cbc0  00000006

复制代码

从卦中看这个 err=6 ，那这个错误码是什么意思呢？继续查 MSDN： https://learn.microsoft.com/zh-cn/windows/win32/debug/system-error-codes--0-499-

从卦中可以清晰的看到，原来是 无效的句柄 导致的，那这个错误会导致程序的卡死吗？
2. 无效的句柄会卡程序吗

按照我的过往经验没有这么一说，其实 win32api 不像编程语言直接用 try catch 与 SEH 集成，返回错误码的这种方式编码起来虽然麻烦，但性能是最高的，所以这玩意导致程序卡死基本上是不可能的，那接下来的分析方向在哪里呢？ 其实在这种场景下抓多dump就尤为重要了，毕竟多个dump之间可以相互参考来观察程序的走势，目前是没有这个条件的，那就从其他的路子上探究吧。
接下来我们试探性的观察所有的托管线程栈，看看他们此时都在做什么。

1. 0:000> ~*e !clrstack
2. OS Thread Id: 0x555c (98)
3.         Child SP               IP Call Site
4. 000000ef180fd0b8 00007ffd01a4dc04 [HelperMethodFrame_1OBJ: 000000ef180fd0b8] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
5. 000000ef180fd1e0 00007ffce4e2ddfc System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
6. 000000ef180fd210 00007ffce4e2ddcf System.Threading.WaitHandle.WaitOne(Int32, Boolean)
7. 000000ef180fd250 00007ffcb5573d74 System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle)
8. 000000ef180fd2c0 00007ffcb4dc0d54 System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control, System.Delegate, System.Object[], Boolean)
9. 000000ef180fd400 00007ffcb5577674 System.Windows.Forms.Control.Invoke(System.Delegate, System.Object[])
10. 000000ef180fd470 00007ffc882040d4 xxxx.backgroundWorker_ProgressChanged(System.Object, System.ComponentModel.ProgressChangedEventArgs)
11. 000000ef180fe060 00007ffce4e1ae56 System.Threading.ThreadPoolWorkQueue.Dispatch()
13. OS Thread Id: 0x4528 (101)
14.         Child SP               IP Call Site
15. 000000ef183fe1d8 00007ffd01a4dc04 [HelperMethodFrame_1OBJ: 000000ef183fe1d8] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
16. 000000ef183fe300 00007ffce4e2ddfc System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
17. 000000ef183fe330 00007ffce4e2ddcf System.Threading.WaitHandle.WaitOne(Int32, Boolean)
18. 000000ef183fe370 00007ffcb5573d74 System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle)
19. 000000ef183fe3e0 00007ffcb4dc0d54 System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control, System.Delegate, System.Object[], Boolean)
20. 000000ef183fe520 00007ffcb5577674 System.Windows.Forms.Control.Invoke(System.Delegate, System.Object[])
21. 000000ef183fe590 00007ffc882040d4 xxxx.backgroundWorker_ProgressChanged(System.Object, System.ComponentModel.
22. 000000ef183ff180 00007ffce4e1ae56 System.Threading.ThreadPoolWorkQueue.Dispatch()
23. 000000ef183ff608 00007ffce66112c3 [DebuggerU2MCatchHandlerFrame: 000000ef183ff608]
24. ...

复制代码

观察上面的线程栈之后，发现有两个线程在 MarshaledInvoke 上等待，而且都是 backgroundWorker_ProgressChanged 方法，看样子有一个 backgroundWorker 控件在这里，其实这个信息还是值得警惕的，为什么这么说呢？ 因为它往往会预示着这个 Control 的 Queue 队列可能有很多的数据积压，那就往这个方向走。
3. Queue 队列有积压吗

要找到这个答案，需要观察主线程的线程栈上是否有 Queue 队列。

1. 0:000> !dso
2. OS Thread Id: 0x918 (0)
3. RSP/REG          Object           Name
4. r13              000002a70660a860 System.Drawing.StringFormat
5. ...
6. 000000EF11D1D9B0 000002a7008b5a18 System.ComponentModel.BackgroundWorker
7. ...
8. 000000EF11D1E328 000002a7004ea8b8 System.Collections.Queue
9. ...
10. 0:000> !do 000002a7004ea8b8
11. Name:        System.Collections.Queue
12. MethodTable: 00007ffce48cd9d0
13. EEClass:     00007ffce49f5fd0
14. Size:        56(0x38) bytes
15. File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
16. Fields:
17.               MT    Field   Offset                 Type VT     Attr            Value Name
18. 00007ffce48d0ba0  40018c3        8      System.Object[]  0 instance 000002a7039d3278 _array
19. 00007ffce48d32c0  40018c4       18         System.Int32  1 instance              103 _head
20. 00007ffce48d32c0  40018c5       1c         System.Int32  1 instance               74 _tail
21. 00007ffce48d32c0  40018c6       20         System.Int32  1 instance              227 _size
22. 00007ffce48d32c0  40018c7       24         System.Int32  1 instance              200 _growFactor
23. 00007ffce48d32c0  40018c8       28         System.Int32  1 instance             1366 _version
24. 00007ffce48d0b08  40018c9       10        System.Object  0 instance 0000000000000000 _syncRoot

复制代码

从卦中数据看，这个 BackgroundWorker.Queue 当前有 227 个任务在队列积压，这说明主线程是没有问题的，只不过是在忙碌的处理任务而已，再回答最后一个问题，为什么会卡一阵子？
4. 为什么会卡一阵子

这是朋友提到的一个疑问，要想找到这个问题的答案，我们再回头看下主线程，看下它是如何从 Queue 中取数据的。

1. 0:000> !clrstack
2. OS Thread Id: 0x918 (0)
3.         Child SP               IP Call Site
4. 000000ef11d1cd70 00007ffd01a007b8 [InlinedCallFrame: 000000ef11d1cd70] System.Drawing.SafeNativeMethods+Gdip.GdipCreateStringFormat(System.Drawing.StringFormatFlags, Int32, IntPtr ByRef)
5. ...
6. 000000ef11d1d970 00007ffc87911aac xxx.backgroundWorker_ProgressChanged(System.Object, System.ComponentModel.ProgressChangedEventArgs)
7. 000000ef11d1d9e0 00007ffcdeab652b System.ComponentModel.BackgroundWorker.OnProgressChanged(System.ComponentModel.ProgressChangedEventArgs)
8. 000000ef11d1dc30 00007ffce66112c3 [DebuggerU2MCatchHandlerFrame: 000000ef11d1dc30]
9. 000000ef11d1dea8 00007ffce66112c3 [HelperMethodFrame_PROTECTOBJ: 000000ef11d1dea8] System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean)
10. 000000ef11d1e020 00007ffce4dfcf58 System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(System.Object, System.Object[], System.Object[])
11. 000000ef11d1e080 00007ffce4dcbd20 System.Delegate.DynamicInvokeImpl(System.Object[])
12. 000000ef11d1e0d0 00007ffcb4dc702d System.Windows.Forms.Control.InvokeMarshaledCallbackDo(ThreadMethodEntry)
13. 000000ef11d1e110 00007ffcb4dc6f49 System.Windows.Forms.Control.InvokeMarshaledCallbackHelper(System.Object)
14. 000000ef11d1e160 00007ffce4ddfbe8 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
15. 000000ef11d1e230 00007ffce4ddfad5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
16. 000000ef11d1e260 00007ffce4ddfaa5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
17. 000000ef11d1e2b0 00007ffcb4dc6ecc System.Windows.Forms.Control.InvokeMarshaledCallback(ThreadMethodEntry)
18. 000000ef11d1e300 00007ffcb4dc6c36 System.Windows.Forms.Control.InvokeMarshaledCallbacks()
19. 000000ef11d1e370 00007ffcb4db06fb System.Windows.Forms.Control.WndProc(System.Windows.Forms.Message ByRef)
20. 000000ef11d1e430 00007ffcb4dafa72 System.Windows.Forms.NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr)
21. 000000ef11d1e4d0 00007ffcb553d682 DomainBoundILStubClass.IL_STUB_ReversePInvoke(Int64, Int32, Int64, Int64)
22. 000000ef11d1e810 00007ffce660fc9e [InlinedCallFrame: 000000ef11d1e810] System.Windows.Forms.UnsafeNativeMethods.DispatchMessageW(MSG ByRef)
23. ...
24. 000000ef11d1ea30 00007ffcb4dc5982 System.Windows.Forms.Application+ThreadContext.RunMessageLoop(Int32, System.Windows.Forms.ApplicationContext)
25. 000000ef11d1ecd0 00007ffc86e308e0 xxx.Program.Main(System.String[])
26. 000000ef11d1ef08 00007ffce66112c3 [GCFrame: 000000ef11d1ef08]

复制代码

从卦中看，线程栈上的 InvokeMarshaledCallback 方法就是取数据的函数，接下来用 ILSpy 反编译下这段代码，简化后如下：
[code]private void InvokeMarshaledCallbacks(){        ThreadMethodEntry threadMethodEntry = null;        lock(threadCallbackList)        {                if (threadCallbackList.Count > 0)                {                        threadMethodEntry = (ThreadMethodEntry)threadCallbackList.Dequeue();                }        }        while (threadMethodEntry != null)        {                try                {                        InvokeMarshaledCallback(threadMethodEntry);                }                catch (Exception ex)                {                        threadMethodEntry.exception = ex.GetBaseException();                }                lock(threadCallbackList)                {                        threadMethodEntry = ((threadCallbackList.Count