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

net · 浏览次数 : 0

小编点评

**背景** - 讲故事:分享了一个训练营学员从零基础到分析得心应手的故事。 - 所涉及到的技术:Windbg、C#、.NET、Visual Automation、Windows Forms、WPF。 **分析过程** **为何会卡死** 1. 使用k命令开启调试器。 2. 分析线程栈,找到NT线程等待多个对象的地点。 3. 跟进堆栈发现,正在等待一个第三方SDK库(PylonBase_v5_1)的Camera数组的释放。 4. 这个库没有pdb文件,只能通过逆向推测方法。 **如何解读** - NtWaitForMultipleObjects:msdn链接 [在这里](https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/windbg---ntwaitformultipleobjects) - 函数原型:`DWORD WaitForMultipleObjects( [in] DWORD nCount, [in] const HANDLE *lpHandles, [in] BOOL bWaitAll, [in] DWORD dwMilliseconds);` - 取地址:`0:000000e4`c0cf87e8 00007ff8`d54f7ff7 ntdll!NtWaitForMultipleObjects+0x14 - 提取 `lpHandles` 中的 handle 值:`000000e4c0cf8b58` **f44 号线程** 1. 在这个线程中,看到了一个等待锁的同步块。 2. 查看同步块索引:`SyncBlock MonitorHeld Recursion_OWNING Thread Info SyncBlock Owner 321 000002ae81012218 7 4 000002ae83701520 2e74 57 000002aedea354e8` **2e74号线程正在做什么** 1. 使用`waitone`函数等待`WaitHandle`。 2. 这个`waitone`是在`System.Windows.Forms.Control`类里面的。 **结论与改进方案** - 这个dump展示了一个典型的三角循环死锁问题。 - 改进方案是将`Invoke`改成`BeginInvoke`以减小锁的粒度,避免死锁产生。

正文

一:背景

1. 讲故事

今天分享的dump是训练营里一位学员的,从一个啥也不会到现在分析的有模有样,真的是看他成长起来的,调试技术学会了就是真真实实自己的,话不多说,上windbg说话。

二:WinDbg 分析

1. 为什么会卡死

这位学员是从事工控大类下的视觉自动化,也是目前.NET的主战场,这个场景下大多都是WPF或者WinForm程序,不管是什么程序,先用命令 k 开路。


0:000> ~0s
ntdll!NtWaitForMultipleObjects+0x14:
00007ff8`d825cc14 c3              ret
0:000> k
 # Child-SP          RetAddr               Call Site
00 000000e4`c0cf87e8 00007ff8`d54f7ff7     ntdll!NtWaitForMultipleObjects+0x14
01 000000e4`c0cf87f0 00007ff8`83aa7585     KERNELBASE!WaitForMultipleObjectsEx+0x107
02 000000e4`c0cf8af0 00007ff8`83aa76fa     PylonBase_v5_1!Pylon::CInstantCameraArray::DestroyInstantCamera+0x78da1
03 000000e4`c0cf8bb0 00007ff8`83a188bc     PylonBase_v5_1!Pylon::CInstantCameraArray::DestroyInstantCamera+0x78f16
04 000000e4`c0cf8c30 00007ff8`83a22a70     PylonBase_v5_1!Pylon::CGrabResultPtr::IsUnique+0x16ec
05 000000e4`c0cf8cd0 00007ff8`41fee2dd     PylonBase_v5_1!Pylon::CGrabResultPtr::IsUnique+0xb8a0
06 000000e4`c0cf8d40 00007ff8`4218711b     0x00007ff8`41fee2dd
...

从卦象看真的很不吉利,因为这个等待是一个第三方的SDK库,从 DestroyInstantCamera 名字看就是 立即销毁相机,接下来我们看下 PylonBase_v5_1 是何方圣神?


0:000> lmvm PylonBase_v5_1
Browse full module list
start             end                 module name
00007ff8`839e0000 00007ff8`83b5b000   PylonBase_v5_1   (export symbols)       PylonBase_v5_1.dll
    Loaded symbol image file: PylonBase_v5_1.dll
    Image path: C:\Program Files\Basler\pylon 5\Runtime\x64\PylonBase_v5_1.dll
    Image name: PylonBase_v5_1.dll
    Browse all global symbols  functions  data
    Timestamp:        Fri Aug 24 20:41:55 2018 (5B7FFD13)
    CheckSum:         0017E66C
    ImageSize:        0017B000
    File version:     5.1.0.12681
    Product version:  5.1.0.12681
    File flags:       0 (Mask 3F)
    File OS:          40004 NT Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0000.04b0
    Information from resource tables:
        CompanyName:      Basler
        ProductName:      Basler pylon
        InternalName:     PylonBase
        OriginalFilename: PylonBase.dll
        ProductVersion:   5.1.0.12681 
        FileVersion:      5.1.0.12681
        PrivateBuild:     
        SpecialBuild:     0
        FileDescription:  PylonBase Module
        LegalCopyright:   Copyright (c) 2006-2018 Basler AG - All rights reserved.
        LegalTrademarks:  
        Comments:         1d4ccf9b36037580c4655fde004335702d90d3e8

由于我是行外人,所以我好奇的查一下 Basler 是什么公司,🐂👃哈,截图如下:

再回过头来看,为什么会在这里被卡呢?这个库是商业产品没有pdb的,看汇编很难推进,索性就从线程栈中逆向推测,即从 NtWaitForMultipleObjects 方法入手。

2. 如何解读 NtWaitForMultipleObjects

这个方法是微软公开的方法,和C#的 Task.WaitAny 功能等价,在 MSDN 上可以看到它的签名信息。


DWORD WaitForMultipleObjects(
  [in] DWORD        nCount,
  [in] const HANDLE *lpHandles,
  [in] BOOL         bWaitAll,
  [in] DWORD        dwMilliseconds
);

接下来就是提取 lpHandles 中的 handle 值,看下这个 handle 到底是什么类型,再图后续方向,根据x64调用协定,只需要提取 rdx 参数即可。


0:000> r
rax=000000000000005b rbx=0000000000000001 rcx=0000000000000001
rdx=000000e4c0cf8b58 rsi=0000000000000000 rdi=0000000000000001
rip=00007ff8d825cc14 rsp=000000e4c0cf87e8 rbp=000000e4c0cf8c00
 r8=000002aedcc62701  r9=ffffffffffffffe8 r10=000002ae86a12580
r11=000000e4c0cf8680 r12=00000000fffffffe r13=000000e4c0cf8b58
r14=000000e4c0cf8840 r15=0000000000000000
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!NtWaitForMultipleObjects+0x14:
00007ff8`d825cc14 c3              ret

0:000> !handle poi(000000e4c0cf8b58) f
Handle 0000000000001790
  Type         	Thread
  Attributes   	0
  GrantedAccess	0x1fffff:
         Delete,ReadControl,WriteDac,WriteOwner,Synch
         Terminate,Suspend,Alert,GetContext,SetContext,SetInfo,QueryInfo,SetToken,Impersonate,DirectImpersonate
  HandleCount  	6
  PointerCount 	201480
  Name         	<none>
  Object specific information
    Thread Id   4714.ff4
    Priority    10
    Base Priority 0

从卦中数据看,居然是一个线程句柄,而且信息 Thread Id 4714.ff4也标出来了,真tmd的是 山重水复疑无路,柳暗花明又一村 。。。

3. f44号线程正在做什么

有了线索之后,后面就是顺藤摸瓜了,先切到 f44 号线程。


0:137> !clrstack
OS Thread Id: 0xff4 (137)
        Child SP               IP Call Site
000000e4c53fd418 00007ff8d825cc14 [GCFrame: 000000e4c53fd418] 
000000e4c53fd610 00007ff8d825cc14 [GCFrame: 000000e4c53fd610] 
000000e4c53fd668 00007ff8d825cc14 [HelperMethodFrame: 000000e4c53fd668] System.Threading.Monitor.Enter(System.Object)
000000e4c53fd760 00007ff84218d827 Basler.xxx.OnImageGrabbed(System.Object, Basler.Pylon.ImageGrabbedEventArgs)
...

从卦象看,这个线程正在 lock锁上等待,那这个lock锁被谁持有着呢?这个就比较简单了,查看下同步块索引即可。


0:137> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
  321 000002ae81012218            7         1 000002ae83701520 2e74  57   000002aedea354e8 System.Object

卦中的 2e74号线程正是持有锁,接下来就是探究下 2e74号线程此时正在干什么?

4. 2e74号线程正在干什么

一路摸瓜,有种预感马上就能看到光了,切到这个线程继续观察。


0:057> !clrstack
OS Thread Id: 0x2e74 (57)
        Child SP               IP Call Site
000000e4c4efcdb8 00007ff8d825cc14 [HelperMethodFrame_1OBJ: 000000e4c4efcdb8] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
000000e4c4efcee0 00007ff89ed99ccc System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 243]
000000e4c4efcf10 00007ff89ed99c9f System.Threading.WaitHandle.WaitOne(Int32, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 194]
000000e4c4efcf50 00007ff89af8ac84 System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle)
000000e4c4efcfc0 00007ff89a7f3264 System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control, System.Delegate, System.Object[], Boolean)
000000e4c4efd100 00007ff89af8e4a4 System.Windows.Forms.Control.Invoke(System.Delegate, System.Object[])
000000e4c4efd170 00007ff84219c223 xxx.MCamera_RetrieveImageCompleted1(System.Object, System.EventArgs)
...

从卦中看这个线程正在用 Invoke 给主线程的 Queue 塞数据,并等待主线程的提取唤醒,所以这是一个经典的 三角循环死锁

有了完整的前因后果之后,改动方案就比较简单了。

  • Invoke 改成 BeginInvoke
  • 缩小 lock 的粒度

三:总结

这个dump所呈现的 三角循环死锁 还是非常经典的,更开心的是这位学员的分析能力已经出了新手村。。。

图片名称

与记一次 .NET某工控视觉自动化系统 卡死分析相似的内容:

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

一:背景 1. 讲故事 今天分享的dump是训练营里一位学员的,从一个啥也不会到现在分析的有模有样,真的是看他成长起来的,调试技术学会了就是真真实实自己的,话不多说,上windbg说话。 二:WinDbg 分析 1. 为什么会卡死 这位学员是从事工控大类下的视觉自动化,也是目前.NET的主战场,这个

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

## 一:背景 ### 1. 讲故事 前段时间有位朋友找到我,说他们的工业视觉软件僵死了,让我帮忙看下到底是什么情况,哈哈,其实卡死的问题相对好定位,无非就是看主线程栈嘛,然后就是具体问题具体分析,当然难度大小就看运气了。 前几天看一篇文章说现在的 .NET程序员 不需要学习**WinDbg** ,

记一次 .NET某工控WPF程序被人恶搞的 卡死分析

一:背景 1. 讲故事 这一期程序故障除了做原理分析,还顺带吐槽一下,熟悉我的朋友都知道我分析dump是免费的,但免费不代表可以滥用我的宝贵时间,我不知道有些人故意恶搞卡死是想干嘛,不得而知,希望后面类似的事情越来越少吧!废话不多说,我们来看看是如何被恶搞的。 二:WinDbg 分析 1. 程序是如

记一次.NET某工控图片上传CPU爆高分析

一:背景 1.讲故事 今天给大家带来一个入门级的 CPU 爆高案例,前段时间有位朋友找到我,说他的程序间歇性的 CPU 爆高,不知道是啥情况,让我帮忙看下,既然找到我,那就用 WinDbg 看一下。 二:WinDbg 分析 1. CPU 真的爆高吗 其实我一直都在强调,要相信数据,口说无凭,一定要亲

记一次 .NET 某工控软件 内存泄露分析

一:背景 1.讲故事 上个月 .NET调试训练营 里的一位老朋友给我发了一个 8G 的dump文件,说他的程序内存泄露了,一时也没找出来是哪里的问题,让我帮忙看下到底是怎么回事,毕竟有了一些调试功底也没分析出来,说明还是有一点复杂的,现实世界中的dump远比课上说的复杂的多。 还是那句话,找我分析是

记一次 .NET 某工控MES程序 崩溃分析

一:背景 1.讲故事 前几天有位朋友找到我,说他的程序出现了偶发性崩溃,已经抓到了dump文件,Windows事件日志显示的崩溃点在 clr.dll 中,让我帮忙看下是怎么回事,那到底怎么回事呢? 上 WinDbg 说话。 二:WinDbg 分析 1. 崩溃点在哪里 如果是托管代码引发的崩溃,在线程

记一次 .NET某工厂报警监控设置 崩溃分析

一:背景 1. 讲故事 前些天有位朋友在微信上丢了一个崩溃的dump给我,让我帮忙看下为什么出现了崩溃,在 Windows 的事件查看器上显示的是经典的 访问违例 ,即 c0000005 错误码,不管怎么说有dump就可以上windbg开干了。 二:WinDbg 分析 1. 程序为谁崩溃了 在 Wi

记一次 .NET某工业设计软件 崩溃分析

一:背景 1. 讲故事 前些天有位朋友找到我,说他的软件在客户那边不知道什么原因崩掉了,从windows事件日志看崩溃在 clr 里,让我能否帮忙定位下,dump 也抓到了,既然dump有了,接下来就上 windbg 分析吧。 二:WinDbg 分析 1. 为什么崩溃在 clr 一般来说崩溃在clr

记一次 .NET 某餐饮小程序 内存暴涨分析

一:背景 1. 讲故事 前些天有位朋友找到我,说他的程序内存异常高,用 vs诊断工具 加载时间又太久,让我帮忙看一下到底咋回事,截图如下: 确实,如果dump文件超过 10G 之后,市面上那些可视化工具分析起来会让你崩溃的,除了时间久之外这些工具大多也不是用懒加载的方式,比如 dotmemory 会

记一次 .NET某报关系统 非托管泄露分析

## 一:背景 ### 1. 讲故事 前段时间有位朋友找到我,说他的程序内存会出现暴涨,让我看下是怎么事情?而且还告诉我是在 Linux 环境下,说实话在Linux上分析.NET程序难度会很大,难度大的原因在于Linux上的各种开源工具主要是针对 C/C++, 和 .NET 一毛钱关系都没有,说到底