【全球独家】记一次 .NET 某医院门诊软件 卡死分析
前几天有位朋友找到我,说他们的软件在客户那边卡死了,让我帮忙看下是怎么回事?我就让朋友在程序卡死的时候通过任务管理器抓一个 dump 下来,虽然默认抓的是 wow64 ,不过用soswow64.dll转还是可以的,参考命令如下:
.load C:\soft\soswow64\soswow64.dll !wow64exts.sw
接下来就可以分析了哈。
(资料图片)
二:WinDbg 分析1. 为什么会卡死首先用!t简单看一下主线程的 COM Apartment 模式,如果是 STA 那就是窗体程序,比如 WPF,WinForm 之类的,输出如下:
0:000:x86> !tThreadCount: 39UnstartedThread: 0BackgroundThread: 12PendingThread: 0DeadThread: 26Hosted Runtime: no Lock ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception 0 1 1928 01aee0b0 2026020 Preemptive 041D496C:00000000 01ae88a8 2 STA ...
既然是窗体程序那就看主线程吧,使用~0s;!clrstack命令。
0:000:x86> !clrstackOS Thread Id: 0x1928 (0)Child SP IP Call Site0177dff8 0167e1f8 [HelperMethodFrame_1OBJ: 0177dff8] System.Threading.SynchronizationContext.WaitHelper(IntPtr[], Boolean, Int32)0177e29c 6a6fc693 System.Windows.Threading.DispatcherSynchronizationContext.Wait(IntPtr[], Boolean, Int32)0177e2b0 71e36d54 System.Threading.SynchronizationContext.InvokeWaitMethodHelper(System.Threading.SynchronizationContext, IntPtr[], Boolean, Int32) [f:\dd\ndp\clr\src\BCL\system\threading\synchronizationcontext.cs @ 349]0177e4d8 73220076 [GCFrame: 0177e4d8] 0177e5f8 73220076 [GCFrame: 0177e5f8] 0177e6d8 73220076 [GCFrame: 0177e6d8] 0177e6f4 73220076 [HelperMethodFrame_1OBJ: 0177e6f4] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)0177e770 18078b93 System.Speech.Internal.Synthesis.AudioDeviceOut.Abort()0177e79c 17270698 System.Speech.Internal.Synthesis.VoiceSynthesis.Abort()0177e7e8 065ec76b System.Speech.Synthesis.SpeechSynthesizer.SpeakAsyncCancelAll()0177e7f0 065ec728 xxx.xxx.Speek(System.String)...
从卦中看是一个语音模块,还有 Speek 功能,挺有意思。。。还 Speek 啥呢?可以用!mdso看一下。
0:000:x86> !mdsoThread 0:Location Object Type------------------------------------------------------------0177e060 04176eb8 System.IntPtr[]...0177e7f8 03be9504 System.String "请先登录验证身份"
哈哈,上面只是花絮,继续看线程栈会发现代码卡在Monitor.ReliableEnter上,也就是等待 lock 锁,接下来用 kb 把 锁对象提取出来,即 clr!JITutil_MonReliableEnter 方法的第一个参数03be11b4,输出如下:
0:000:x86> kb...17 0177e768 18078b93 03be11b4 00000000 00000000 clr!JITutil_MonReliableEnter+0xb518 0177e794 17270698 0177e7bc 73252799 00000000 0x18078b9319 0177e7e0 065ec76b 0177e808 065ec728 00000000 0x172706981a 0177e7e8 065ec728 00000000 03a0b318 03be9504 0x65ec76b1b 0177e808 1727e09f 00000000 03be0920 04158b98 0x65ec7281c 0177e824 69181324 04175c04 041199c0 00000001 0x1727e09f...0:000:x86> !do 03be11b4Name: System.ObjectMethodTable: 71f200f4EEClass: 71a715b0Size: 12(0xc) bytesFile: C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dllObjectFields:None
有了这个对象就可以用!syncblk命令观察同步块表,到底是哪个线程在持有不释放?
0:000:x86> !syncblkIndex SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner 96 11ac3ee0 3 1 11af0f28 35d4 13 03be11b4 System.Object-----------------------------Total 931CCW 39RCW 19ComClassFactory 2Free 8020:000:x86> ~13s;!clrstackntdll_76fc0000!NtWaitForSingleObject+0xc:7703159c c20c00 ret 0ChOS Thread Id: 0x35d4 (13)Child SP IP Call Site17f8f23c 0000002b [InlinedCallFrame: 17f8f23c] 17f8f238 1adf3269 DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr)17f8f23c 1adf2e82 [InlinedCallFrame: 17f8f23c] System.Speech.Internal.Synthesis.SafeNativeMethods.waveOutClose(IntPtr)17f8f26c 1adf2e82 System.Speech.Internal.Synthesis.AudioDeviceOut.End()17f8f298 187a5cd6 System.Speech.Internal.Synthesis.VoiceSynthesis.SpeakText(System.Speech.Internal.Synthesis.SpeakInfo, System.Speech.Synthesis.Prompt, System.Collections.Generic.List`1)17f8f304 17271669 System.Speech.Internal.Synthesis.VoiceSynthesis.ThreadProc()17f8f3b8 71e3710d System.Threading.ThreadHelper.ThreadStart_Context(System.Object) [f:\dd\ndp\clr\src\BCL\system\threading\thread.cs @ 74]17f8f3c4 71e640c5 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 954]17f8f430 71e63fd6 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 902]17f8f444 71e63f91 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 891]17f8f45c 71e37068 System.Threading.ThreadHelper.ThreadStart() [f:\dd\ndp\clr\src\BCL\system\threading\thread.cs @ 111]17f8f5a0 73220076 [GCFrame: 17f8f5a0] 17f8f784 73220076 [DebuggerU2MCatchHandlerFrame: 17f8f784] 0:013:x86> !t ... 13 14 35d4 11af0f28 2b220 Preemptive 00000000:00000000 01ae88a8 2 MTA ...
从卦中信息看:13号线程持有了 lock 锁,并且它非线程池线程,而是通过new Thread出来的,从线程栈看都是sdk函数,综合这些信息,应该是VoiceSynthesis创建出来的后台线程,下面的图也可以佐证。
接下来继续看,从线程栈顶上可以观察到最后卡在了System.Speech.Internal.Synthesis.SafeNativeMethods.waveOutClose方法处,逆向之后的代码如下:
// System.Speech.Internal.Synthesis.AudioDeviceOut internal override void End() { if (!_deviceOpen) { throw new InvalidOperationException(); } lock (_noWriteOutLock) { _deviceOpen = false; CheckForAbort(); if (_queueIn.Count != 0) { SafeNativeMethods.waveOutReset(_hwo); } MMSYSERR mMSYSERR = SafeNativeMethods.waveOutClose(_hwo); } }
由于这是 Windows 的 VoiceSynthesis 模块封装底层函数,经过千锤百炼,理论上出问题的概率会非常小,除非上层有不合理的调用,这种概率会大一些。
2. 是上层不合理的调用吗这一块我也没玩过,网上搜一下waveOutReset,waveOutClose,看下有没有同病相怜的人,结果网上一搜一堆,比如下面这样:
不管怎么说,这一块如果处理不好容易出现死锁和卡死的情况,那是不是正如图中所说waveOutReset和waveOutClose没有匹配造成的呢?
这就取决于代码中的_queueIn集合,可以观察这两个函数的汇编代码提取出这个变量。
0:013:x86> !U /d 1adf2e82Normal JIT generated codeSystem.Speech.Internal.Synthesis.AudioDeviceOut.End()...1adf2e30 8bf1 mov esi,ecx...1adf2e69 8b4608 mov eax,dword ptr [esi+8]1adf2e6c 83780c00 cmp dword ptr [eax+0Ch],01adf2e70 7408 je 1adf2e7a...0:013:x86> !U /d 187a5cd6Normal JIT generated codeSystem.Speech.Internal.Synthesis.VoiceSynthesis.SpeakText(System.Speech.Internal.Synthesis.SpeakInfo, System.Speech.Synthesis.Prompt, System.Collections.Generic.List`1)...187a5cc8 8b45d0 mov eax,dword ptr [ebp-30h]187a5ccb 8b486c mov ecx,dword ptr [eax+6Ch]187a5cd3 ff5014 call dword ptr [eax+14h]>>> 187a5cd6 58 pop eax...0:013:x86> kb 10 # ChildEBP RetAddr Args to Child ...08 17f8f264 1adf2e82 03be11b4 00000001 00000000 0x1adf326909 17f8f290 187a5cd6 187a5e16 03be0d24 043f3520 0x1adf2e820a 17f8f2f4 17271669 040efa14 040ef9a4 732515d8 0x187a5cd60b 17f8f3b0 71e3710d 03ff3e98 17f8f420 71e640c5 0x17271669...
仔细观察上面的汇编代码:eax 来自于 esi,esi 来自于 ecx,ecx 最终来自于父函数中的ebp-30h的位置,串联起来的命令就是!do poi(poi(poi(17f8f2f4-30)+6c)+0x8),接下来我们 do 一下。
0:000:x86> !do poi(poi(poi(17f8f2f4-30)+6c)+0x8)Name: System.Collections.Generic.List`1[[System.Speech.Internal.Synthesis.AudioDeviceOut+InItem, System.Speech]]MethodTable: 16cf20ecEEClass: 71af6f8cSize: 24(0x18) bytesFile: C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dllFields: MT Field Offset Type VT Attr Value Name71f2f320 4001891 4 System.__Canon[] 0 instance 03c74538 _items71f21bb4 4001892 c System.Int32 1 instance 0 _size71f21bb4 4001893 10 System.Int32 1 instance 1900 _version71f200f4 4001894 8 System.Object 0 instance 00000000 _syncRoot71f2f320 4001895 4 System.__Canon[] 0 static
可以看到此时的_size=0,有可能就是因为上层不合理调用导致这里的_queueIn意外为 0 ,最终引发的卡死现象。
3. 真相大白一时之间也找不到上层哪里有不合理的调用,接下来的思路还是自己研读主线程和13号线程的调用栈,最后发现一个可疑的现象,截图如下:
通过仔细研读底层代码,Speek 会将消息丢到底层的queue队列中,后台线程会提取处理,这里的SpeakAsyncCancelAll是完全没必要的。
有了这个消息,就让朋友把这个函数去掉观察下试试,据朋友反馈说没有问题了。
三:总结这个案例中去掉了意外的speech.SpeakAsyncCancelAll();语句就搞定了,内部深层逻辑也没有再探究了,大概率就是意外的 _queueIn 为 0,让waveOutReset和waveOutClose方法没有匹配出现,造成了卡死现象。