记一次 .NET 某工控视觉系统 卡死分析

喝酒误事

一：背景

1. 讲故事

前段时间有位朋友找到我，说他们的工业视觉软件僵死了，让我帮忙看下到底是什么情况，哈哈，其实卡死的问题相对好定位，无非就是看主线程栈嘛，然后就是具体问题具体分析，当然难度大小就看运气了。
前几天看一篇文章说现在的 .NET程序员 不需要学习WinDbg ，理由就是有很多好的分析工具诸如 VS，DnSpy，PerfView 可以替代，我也只能笑笑，在他们的认知中可能 .NET程序 是不需要和其他语言交互而独成一体的。
话不多说，回到主题，上 WinDbg 说话。
二：为什么会卡死

1. 主线程在做什么

刚才也说到了，卡死是比较好定位的，切到主线程看线程栈即可,简化输出如下：

1. 0:000> ~0s;k
2. ntdll!NtDelayExecution+0x14:
3. 00007ffc`7d45fcf4 c3              ret
4. # Child-SP          RetAddr               Call Site
5. 00 00000000`007fd628 00007ffc`79a15631     ntdll!NtDelayExecution+0x14
6. 01 00000000`007fd630 00007ffc`40b7b116     KERNELBASE!SleepEx+0xa1
7. 02 00000000`007fd6d0 00007ffc`40b7372e     cogxstd+0x13b116
8. 03 00000000`007fd700 00007ffc`40b73ece     cogxstd+0x13372e
9. ...
10. 09 00000000`007fd9b0 00007ffc`7d1c77e3     CogDisplay!DllUnregisterServer+0x1833f
11. 0a 00000000`007fdab0 00007ffc`7d16436c     rpcrt4!Invoke+0x73
12. 0b 00000000`007fdb00 00007ffc`7cdbc473     rpcrt4!NdrStubCall2+0x42c
13. 0c 00000000`007fe130 00007ffc`7c451bf0     combase!CStdStubBuffer_Invoke+0x73 [onecore\com\combase\ndr\ndrole\stub.cxx @ 1446]
14. ...
15. 11 00000000`007fe230 00007ffc`7cdc2df6     combase!DefaultStubInvoke+0x1c4 [onecore\com\combase\dcomrem\channelb.cxx @ 1769]
16. 12 (Inline Function) --------`--------     combase!SyncStubCall::Invoke+0x22 [onecore\com\combase\dcomrem\channelb.cxx @ 1826]
17. 13 00000000`007fe380 00007ffc`7cd62e55     combase!SyncServerCall::StubInvoke+0x26 [onecore\com\combase\dcomrem\servercall.hpp @ 825]
18. 14 (Inline Function) --------`--------     combase!StubInvoke+0x265 [onecore\com\combase\dcomrem\channelb.cxx @ 2052]
19. 15 00000000`007fe3c0 00007ffc`7cd8ded2     combase!ServerCall::ContextInvoke+0x435 [onecore\com\combase\dcomrem\ctxchnl.cxx @ 1532]
20. ...
21. 31 00000000`007fff60 00000000`00000000     ntdll!RtlUserThreadStart+0x21

复制代码

从卦中看当前主线程正在 Sleep，这就很奇葩了，并且还是康耐视的 cogxstd 动态链接库的逻辑，这里我敢相信它不会有这么低级的错误，接下来我们洞察下到底 Sleep 了多久，仔细观察汇编代码，精简后如下：

1.     ntdll!NtDelayExecution:
2. 00007ffc`7d45fce0 4c8bd1           mov     r10, rcx
3. 00007ffc`7d45fce3 b834000000       mov     eax, 34h
4. 00007ffc`7d45fce8 f604250803fe7f01 test    byte ptr [7FFE0308h], 1
5. 00007ffc`7d45fcf0 7503             jne     ntdll!NtDelayExecution+0x15 (7ffc7d45fcf5)
6. 00007ffc`7d45fcf2 0f05             syscall
7. 00007ffc`7d45fcf4 c3               ret     
8. 00007ffc`7d45fcf5 cd2e             int     2Eh
9. 00007ffc`7d45fcf7 c3               ret     
10. 00007ffc`7d45fcf8 0f1f840000000000 nop     dword ptr [rax+rax]
12.     KERNELBASE!SleepEx:
13. 00007ffc`79a15590 89542410         mov     dword ptr [rsp+10h], edx
14. 00007ffc`79a15594 4c8bdc           mov     r11, rsp
15. 00007ffc`79a15597 53               push    rbx
16. 00007ffc`79a15598 56               push    rsi
17. 00007ffc`79a15599 57               push    rdi
18. 00007ffc`79a1559a 4881ec80000000   sub     rsp, 80h
19. 00007ffc`79a155a1 8bda             mov     ebx, edx
20. 00007ffc`79a155a3 8bf9             mov     edi, ecx
21. ...
22. 00007ffc`79a155f4 488b9424b8000000 mov     rdx, qword ptr [rsp+0B8h]
23. 00007ffc`79a155fc 85db             test    ebx, ebx
24. 00007ffc`79a155fe 0f8592000000     jne     KERNELBASE!SleepEx+0x106 (7ffc79a15696)
25. 00007ffc`79a15604 83ffff           cmp     edi, 0FFFFFFFFh
26. 00007ffc`79a15607 7443             je      KERNELBASE!SleepEx+0xbc (7ffc79a1564c)
27. 00007ffc`79a15609 4869cf10270000   imul    rcx, rdi, 2710h
28. 00007ffc`79a15610 48894c2420       mov     qword ptr [rsp+20h], rcx
29. 00007ffc`79a15615 48f7d9           neg     rcx
30. ...
31. 00007ffc`79a15622 488d542420       lea     rdx, [rsp+20h]
32. 00007ffc`79a15627 0fb6cb           movzx   ecx, bl
33. 00007ffc`79a1562a 48ff15ef641400   call    qword ptr [KERNELBASE!__imp_NtDelayExecution (7ffc79b5bb20)]

复制代码

再上一段 reactos 的 C++ 方法签名。

1. DWORD
2. WINAPI
3. SleepEx(IN DWORD dwMilliseconds,
4.         IN BOOL bAlertable)
5. {}
7. NTSTATUS
8. NTAPI
9. NtDelayExecution(IN BOOLEAN Alertable,
10.                  IN PLARGE_INTEGER DelayInterval)
11. {}

复制代码

我们要重点观察 NtDelayExecution 方法中 rdx 参数是怎么计算的，重点就是下面的两句汇编。

1. imul    rcx, rdi, 2710h
2. neg     rcx

复制代码

这两句汇编是什么意思呢？ 转成 C++ 代码就是

1. interval = - (milliseconds * 0x2710);

复制代码

在汇编中我们是知道 interval 的，它相当于是 milliseconds 计算后的补码，即下面的 Binary: 列。

1. 0:000> r
2. rax=0000000000000034 rbx=0000000000000000 rcx=0000000000000000
3. rdx=00000000007fd650 rsi=0000000000000000 rdi=0000000000000001
4. rip=00007ffc7d45fcf4 rsp=00000000007fd628 rbp=00000000bf1efcf8
5. r8=00000000007fd628  r9=00000000bf1efcf8 r10=0000000000000000
6. r11=0000000000000246 r12=0000000000000000 r13=0000000000000798
7. r14=000000003bd064b0 r15=00000000bf1efce0
9. 0:000> dp 00000000007fd650 L1
10. 00000000`007fd650  ffffffff`ffffd8f0
12. 0:000> .formats ffffffff`ffffd8f0
13. Evaluate expression:
14.   Hex:     ffffffff`ffffd8f0
15.   Binary:  11111111 11111111 11111111 11111111 11111111 11111111 11011000 11110000
16.   ...

复制代码

那怎么求 milliseconds 呢？ 其实 补码的补码 就是原码，然后再除以 0x2710 就可以获取到 milliseconds 了哈。

• 补码：11111111 11111111 11111111 11111111 11111111 11111111 11011000 11110000
  
• 反码：00000000 00000000 00000000 00000000 00000000 00000000 00100111 00001111
  
• 补补：00000000 00000000 00000000 00000000 00000000 00000000 00100111 00010000
  

1. 0:000> .formats 0y0000000000000000000000000000000000000000000000000010011100010000
2. Evaluate expression:
3.   Hex:     00000000`00002710
4.   Decimal: 10000
5.   Decimal (unsigned) : 10000
6.   Octal:   0000000000000000023420
7.   Binary:  00000000 00000000 00000000 00000000 00000000 00000000 00100111 00010000
9. 0:000> ? 00002710/ 2710
10. Evaluate expression: 1 = 00000000`00000001

复制代码

从卦中看当前也就暂停了 1ms，如果想验证对不对的话，仔细看mov edi, ecx 会发现做了一次备份，但不管怎么说 Thread.Sleep(1) 应该问题不大，那问题在哪里呢？
2. 问题到底在哪里

既然问题不在 Sleep(1) 上那到底在哪里呢？仔细观察线程栈会发现底层做了一个 RPC 通讯，从 combase!SyncServerCall::StubInvoke 和 rpcrt4!NdrStubCall2 方法来看，它是 RPC 的 Server 端，既然是 Server 端就必然有 Client 端，根据经验这个 RPC 应该是 命令管道 的方式，没开 Windows 的RPC诊断所以不能100%确认。
接下来看下其他线程有没有 RPC 的 rpcrt4!NdrpClientCall 请求，抱着试试看的态度搜一搜，我去，还真有10几个，截图如下：

仔细分析这 12 个 Reqeust，发现其中的 Cognex.VisionPro.Display.CogDisplay.set_Image 比较可疑，毕竟 Image 运作起来肯定是费时费力的。

1. 0:543> k
2. # Child-SP          RetAddr               Call Site
3. 00 00000000`fc65def8 00007ffc`79a1c2ce     ntdll!NtWaitForMultipleObjects+0x14
4. ...
5. 04 (Inline Function) --------`--------     combase!CSyncClientCall::SwitchAptAndDispatchCall+0x34a
6. 05 00000000`fc65e290 00007ffc`7cd9b015     combase!CSyncClientCall::SendReceive2+0x42c
7. 06 (Inline Function) --------`--------     combase!SyncClientCallRetryContext::SendReceiveWithRetry+0x25
8. 07 (Inline Function) --------`--------     combase!CSyncClientCall::SendReceiveInRetryContext+0x25
9. 08 00000000`fc65e480 00007ffc`7cd8c55d     combase!DefaultSendReceive+0x65
10. 09 00000000`fc65e4e0 00007ffc`7cd60a54     combase!CSyncClientCall::SendReceive+0x12d
11. 0a 00000000`fc65e710 00007ffc`7cdbc54e     combase!CClientChannel::SendReceive+0x84
12. 0b 00000000`fc65e780 00007ffc`7d151e93     combase!NdrExtpProxySendReceive+0x4e
13. 0c 00000000`fc65e7b0 00007ffc`7cdbae17     rpcrt4!NdrpClientCall2+0x463
14. 0d 00000000`fc65edf0 00007ffc`7ce2ce92     combase!ObjectStublessClient+0x1d7
15. 0e 00000000`fc65f180 00007ffb`f1321db8     combase!ObjectStubless+0x42
16. 0f 00000000`fc65f1d0 00007ffc`4002c906     0x00007ffb`f1321db8
17. 10 00000000`fc65f2c0 00007ffb`f131d541     Cognex_VisionPro_Display_Controls_ni!Cognex.VisionPro.Display.CogDisplay.set_Image+0xb6
19. 0:543> !clrstack
20. OS Thread Id: 0x2bbc (543)
21.         Child SP               IP Call Site
22. ...
23. 00000000fc65f208 00007ffbf1321db8 [InlinedCallFrame: 00000000fc65f208] Cognex.VisionPro.Interop.CogDisplayClass.set_Image(Cognex.VisionPro.Interop.ICogImage)
24. 00000000fc65f1d0 00007ffbf1321db8 DomainBoundILStubClass.IL_STUB_CLRtoCOM(Cognex.VisionPro.Interop.ICogImage)
25. 00000000fc65f2c0 00007ffc4002c906 Cognex.VisionPro.Display.CogDisplay.set_Image(Cognex.VisionPro.ICogImage)
26. 00000000fc65f310 00007ffbf131d541 xxxx.SetDefaultRecord()
27. ...
28. 00000000fc65f680 00007ffc4bc17e46 System.Threading.ThreadPoolWorkQueue.Dispatch()
29. 00000000fc65fb20 00007ffc4d706c93 [DebuggerU2MCatchHandlerFrame: 00000000fc65fb20]

复制代码

根据卦中的托管方法 xxxx.SetDefaultRecord() ，让朋友不要做 Image 赋值观察下效果，朋友反馈说，这个 Image 不赋值问题就没有了。
既然去掉就好了，到这里只能推测当前主线程不是卡死，而是 RPC 请求过多Size过大，导致主线程一直忙碌中，具体为什么会忙碌，这就需要逆向 cogxstd 来滤清业务逻辑了，这个就太费时费力了，还是先绕过去为好。
三：总结

还是回到文章开头的那句话，这种 dump 问题，你能用 DnSpy，VS 调试出来吗？说实话很难，虽然以 .NET 程序为出口，但考察了你很多基础知识，诸如 RPC，COM，汇编，没有这些基础沉淀，这类dump很难摸清来龙去脉。

来源:https://www.cnblogs.com/huangxincheng/archive/2023/07/04/17525483.html
免责声明：由于采集信息均来自互联网，如果侵犯了您的权益，请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容，谢谢合作！