記一次 .NET某工控視覺自動(dòng)化系統(tǒng)卡死分析
一、背景
1. 講故事
今天分享的dump是訓(xùn)練營(yíng)里一位學(xué)員的,從一個(gè)啥也不會(huì)到現(xiàn)在分析的有模有樣,真的是看他成長(zhǎng)起來的,調(diào)試技術(shù)學(xué)會(huì)了就是真真實(shí)實(shí)自己的,話不多說,上windbg說話。
二、WinDbg 分析
1. 為什么會(huì)卡死
這位學(xué)員是從事工控大類下的視覺自動(dòng)化,也是目前.NET的主戰(zhàn)場(chǎng),這個(gè)場(chǎng)景下大多都是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
...
從卦象看真的很不吉利,因?yàn)檫@個(gè)等待是一個(gè)第三方的SDK庫(kù),從 DestroyInstantCamera 名字看就是 立即銷毀相機(jī),接下來我們看下 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 是什么公司,????哈,截圖如下:
圖片
再回過頭來看,為什么會(huì)在這里被卡呢?這個(gè)庫(kù)是商業(yè)產(chǎn)品沒有pdb的,看匯編很難推進(jìn),索性就從線程棧中逆向推測(cè),即從 NtWaitForMultipleObjects 方法入手。
2. 如何解讀 NtWaitForMultipleObjects
這個(gè)方法是微軟公開的方法,和C#的 Task.WaitAny 功能等價(jià),在 MSDN 上可以看到它的簽名信息。
DWORD WaitForMultipleObjects(
[in] DWORD nCount,
[in] const HANDLE *lpHandles,
[in] BOOL bWaitAll,
[in] DWORD dwMilliseconds
);
接下來就是提取 lpHandles 中的 handle 值,看下這個(gè) handle 到底是什么類型,再圖后續(xù)方向,根據(jù)x64調(diào)用協(xié)定,只需要提取 rdx 參數(shù)即可。
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
從卦中數(shù)據(jù)看,居然是一個(gè)線程句柄,而且信息 Thread Id 4714.ff4也標(biāo)出來了,真tmd的是 山重水復(fù)疑無路,柳暗花明又一村 。。。
3. f44號(hào)線程正在做什么
有了線索之后,后面就是順藤摸瓜了,先切到 f44 號(hào)線程。
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)
...
從卦象看,這個(gè)線程正在 lock鎖上等待,那這個(gè)lock鎖被誰(shuí)持有著呢?這個(gè)就比較簡(jiǎn)單了,查看下同步塊索引即可。
0:137> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner
321 000002ae81012218 7 1 000002ae83701520 2e74 57 000002aedea354e8 System.Object
卦中的 2e74號(hào)線程正是持有鎖,接下來就是探究下 2e74號(hào)線程此時(shí)正在干什么?
4. 2e74號(hào)線程正在干什么
一路摸瓜,有種預(yù)感馬上就能看到光了,切到這個(gè)線程繼續(xù)觀察。
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)
...
從卦中看這個(gè)線程正在用 Invoke 給主線程的 Queue 塞數(shù)據(jù),并等待主線程的提取喚醒,所以這是一個(gè)經(jīng)典的 三角循環(huán)死鎖。
有了完整的前因后果之后,改動(dòng)方案就比較簡(jiǎn)單了。
- Invoke 改成 BeginInvoke
- 縮小 lock 的粒度
三:總結(jié)
這個(gè)dump所呈現(xiàn)的 三角循環(huán)死鎖 還是非常經(jīng)典的,更開心的是這位學(xué)員的分析能力已經(jīng)出了新手村......