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

标签：Threading Windows Object System Forms 上位 Boolean NET 卡死

一：背景

1. 讲故事

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

二：WinDbg 分析

1. 主线程在做什么

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


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

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


void RtlSetLastWin32Error
(
    DWORD err
)

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


0:000> uf ntdll!RtlSetLastWin32Error
ntdll!RtlSetLastWin32Error:
00007ffd`01a00780 894c2408        mov     dword ptr [rsp+8],ecx
00007ffd`01a00784 4883ec48        sub     rsp,48h
00007ffd`01a00788 488b05813d1300  mov     rax,qword ptr [ntdll!_security_cookie (00007ffd`01b34510)]
00007ffd`01a0078f 4833c4          xor     rax,rsp
....

0:000> k
 # Child-SP          RetAddr               Call Site
00 000000ef`11d1cb70 00007ffc`e65ddc4a     ntdll!RtlSetLastWin32Error+0x38
01 000000ef`11d1cbc0 00007ffc`e660e1a4     clr!JIT_RareDisableHelperWorker+0xca

0:000> dd 000000ef`11d1cbc0 L1
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之间可以相互参考来观察程序的走势，目前是没有这个条件的，那就从其他的路子上探究吧。

接下来我们试探性的观察所有的托管线程栈，看看他们此时都在做什么。


0:000> ~*e !clrstack
OS Thread Id: 0x555c (98)
        Child SP               IP Call Site
000000ef180fd0b8 00007ffd01a4dc04 [HelperMethodFrame_1OBJ: 000000ef180fd0b8] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
000000ef180fd1e0 00007ffce4e2ddfc System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
000000ef180fd210 00007ffce4e2ddcf System.Threading.WaitHandle.WaitOne(Int32, Boolean)
000000ef180fd250 00007ffcb5573d74 System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle)
000000ef180fd2c0 00007ffcb4dc0d54 System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control, System.Delegate, System.Object[], Boolean)
000000ef180fd400 00007ffcb5577674 System.Windows.Forms.Control.Invoke(System.Delegate, System.Object[])
000000ef180fd470 00007ffc882040d4 xxxx.backgroundWorker_ProgressChanged(System.Object, System.ComponentModel.ProgressChangedEventArgs)
000000ef180fe060 00007ffce4e1ae56 System.Threading.ThreadPoolWorkQueue.Dispatch() 

OS Thread Id: 0x4528 (101)
        Child SP               IP Call Site
000000ef183fe1d8 00007ffd01a4dc04 [HelperMethodFrame_1OBJ: 000000ef183fe1d8] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
000000ef183fe300 00007ffce4e2ddfc System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
000000ef183fe330 00007ffce4e2ddcf System.Threading.WaitHandle.WaitOne(Int32, Boolean)
000000ef183fe370 00007ffcb5573d74 System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle)
000000ef183fe3e0 00007ffcb4dc0d54 System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control, System.Delegate, System.Object[], Boolean)
000000ef183fe520 00007ffcb5577674 System.Windows.Forms.Control.Invoke(System.Delegate, System.Object[])
000000ef183fe590 00007ffc882040d4 xxxx.backgroundWorker_ProgressChanged(System.Object, System.ComponentModel.
000000ef183ff180 00007ffce4e1ae56 System.Threading.ThreadPoolWorkQueue.Dispatch() 
000000ef183ff608 00007ffce66112c3 [DebuggerU2MCatchHandlerFrame: 000000ef183ff608] 
...

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

3. Queue 队列有积压吗

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


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

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

4. 为什么会卡一阵子

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


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

从卦中看，线程栈上的 InvokeMarshaledCallback 方法就是取数据的函数，接下来用 ILSpy 反编译下这段代码，简化后如下：


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 <= 0) ? null : ((ThreadMethodEntry)threadCallbackList.Dequeue()));
		}
	}
}

从代码中的while true来看，这方法真的很轴，不懂得变通，要么不取，要么就是一次性的取完，当 Queue=threadCallbackList 中的数据较多时，主线程就会非常的忙碌，所以这就是卡死一阵子的真正底层原因。

有了前因后果之后，建议朋友做如下两点修改：

Invoke 的逻辑尽量简单，让 UI 可以秒杀。
Invoke 的逻辑是否可以批量化，来减少 Queue 的积压。

三：总结

这次朋友的生产事故，对我们做分析的人来说还是有很大的教训意义，有时候主线程的一些抛错或者阻塞假象会诱导我们陷入分析误区，这就需要调试人员具有一双慧眼识别，及时的浪子回头。
图片名称

标签：Threading,Windows,Object,System,Forms,上位,Boolean,NET,卡死
From： https://www.cnblogs.com/huangxincheng/p/18253859

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

一：背景

1. 讲故事

二：WinDbg 分析

1. 主线程在做什么

2. 无效的句柄会卡程序吗

3. Queue 队列有积压吗

4. 为什么会卡一阵子

三：总结

相关文章

赞助商

阅读排行

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

一：背景

1. 讲故事

二：WinDbg 分析

1. 主线程在做什么

2. 无效的句柄会卡程序吗

3. Queue 队列有积压吗

4. 为什么会卡一阵子

三：总结

相关文章

赞助商

阅读排行

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