記一次 .NET 某放射治療光學定位軟件卡死分析
一、背景
1. 講故事
前段時間微信上有位非調試訓練營學員找到我,說他們的醫療軟件有點問題,有時候卡了一會就好了,有時候卡了很久,讓我幫忙看下怎么回事,我讓這位朋友在卡的時候抓一個dump給我,我分析看看。
二、卡死分析
1. 為什么會卡死
對于窗體程序的卡死,主要就是看主線程此時正在做什么,使用 ~0s;k 命令即可,輸出如下:
0:000> ~0s;k
PresentationCore_ni!string+0x1e6968:
00007ffb`f4407e60 250000e0ff and eax,0FFE00000h
# Child-SP RetAddr Call Site
00 0000005f`849fc7c0 00007ffb`f4407da7 PresentationCore_ni!`string'+0x1e6968
01 0000005f`849fc810 00007ffb`f43d1d5a PresentationCore_ni!System.Windows.ContextLayoutManager.LayoutQueue.Add+0x37
02 0000005f`849fc860 00007ffb`f2e5a4b8 PresentationCore_ni!System.Windows.UIElement.InvalidateMeasure+0xda
03 0000005f`849fc8b0 00007ffb`f2ead5bd PresentationFramework_ni!System.Windows.FrameworkElement.OnPropertyChanged+0x8b8
04 0000005f`849fcb10 00007ffc`1ae9c394 PresentationFramework_ni!System.Windows.Controls.TextBlock.OnPropertyChanged+0x5d
...
26 0000005f`849fe460 00007ffc`1ae9044f WindowsBase_ni!System.Windows.Threading.Dispatcher.ProcessQueue+0x1fd
27 0000005f`849fe4f0 00007ffc`1ae93314 WindowsBase_ni!System.Windows.Threading.Dispatcher.WndProcHook+0x6f
28 0000005f`849fe570 00007ffc`1ae93714 WindowsBase_ni!MS.Win32.HwndWrapper.WndProc+0xc4
29 0000005f`849fe600 00007ffc`1ae93d58 WindowsBase_ni!MS.Win32.HwndSubclass.DispatcherCallbackOperation+0x84
2a 0000005f`849fe650 00007ffc`1ae93c56 WindowsBase_ni!System.Windows.Threading.ExceptionWrapper.InternalRealCall+0x68
2b 0000005f`849fe6c0 00007ffc`1ae91262 WindowsBase_ni!System.Windows.Threading.ExceptionWrapper.TryCatchWhen+0x36
2c 0000005f`849fe710 00007ffc`1ae93082 WindowsBase_ni!System.Windows.Threading.Dispatcher.LegacyInvokeImpl+0x172
2d 0000005f`849fe7b0 00007ffc`1b053b82 WindowsBase_ni!MS.Win32.HwndSubclass.SubclassWndProc+0x152
2e 0000005f`849fe8b0 00007ffc`2f0e224e WindowsBase_ni+0x323b82
2f 0000005f`849fe920 00007ffc`505ce7e8 clr!UMThunkStub+0x6e
30 0000005f`849fe9b0 00007ffc`505ce229 user32!UserCallWinProcCheckWow+0x2f8
31 0000005f`849feb40 00007ffc`1aeb4479 user32!DispatchMessageWorker+0x249
...
43 0000005f`849ffc60 00000000`00000000 ntdll!RtlUserThreadStart+0x21從卦中的 ProcessQueue, TextBlock.OnPropertyChanged 等函數來看,當前主線程正在忙碌處理,如果你想看主線程的執行流細節,可以將dmp拖到vs中,讓vs幫我們解讀,拖進去后是不是一下子就清晰多了。。。截圖如下:
圖片
接下來的問題是這玩意會導致UI的卡死嗎? 經驗上告訴我,這個概率不大,畢竟 PresentationCore.dll 中的代碼固若金湯,那問題出在哪里呢?大概率就是窗體的Queue隊列積壓過多導致。
2. Queue隊列積壓過多嗎
要想找到這個問題的答案,可以深挖調度類Dispatcher,使用 !dso xxx 到當前線程棧里去撈。
0:000> !dso
OS Thread Id: 0x34d0 (0)
RSP/REG Object Name
...
0000005F849FED20 0000020c4a784dc8 System.Windows.Threading.Dispatcher
...
0:000> !do0000020c4a784dc8
Name: System.Windows.Threading.Dispatcher
MethodTable: 00007ffc1ad53e30
EEClass: 00007ffc1ad8a6f0
Size: 232(0xe8) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_MSIL\WindowsBase\v4.0_4.0.0.0__31bf3856ad364e35\WindowsBase.dll
Fields:
MT Field Offset Type VT Attr Value Name
...
00007ffc1ad4caf8 4001284 a0 ...on, WindowsBase]] 0 instance 0000020c4a784f08 _queue
...
0:000> !do0000020c4a784f08
Name: System.Windows.Threading.PriorityQueue`1[[System.Windows.Threading.DispatcherOperation, WindowsBase]]
MethodTable: 00007ffc1ad4caf8
EEClass: 00007ffc1adab1e8
Size: 56(0x38) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_MSIL\WindowsBase\v4.0_4.0.0.0__31bf3856ad364e35\WindowsBase.dll
Fields:
MT Field Offset Type VT Attr Value Name
00000000000000004001240 8 0 instance 0000020c4a784f40 _priorityChains
00000000000000004001241 10 0 instance 0000020c4a785078 _cacheReusableChains
00007ffc1b18f340 4001242 18 ...Canon, mscorlib]] 0 instance 0000020c31b84d68 _head
00007ffc1b18f340 4001243 20 ...Canon, mscorlib]] 0 instance 0000020ce073ca68 _tail
00007ffc2b4d85a0 4001244 28 System.Int32 1 instance 889015 _count這卦象很不吉利,UI 隊列居然積壓了高達 88w 的未處理任務,難怪這位朋友說軟件卡死了,其實UI線程在忙碌的任務處理,看樣子沒個幾天幾夜搞不定哈。
接下來的問題是為什么會積壓這么多,要想找到這個問題的答案,可以從 88w 的queue隊列中抽選幾個任務,看看大概都是些什么,展開上面的 _tail 節點即可。
0:000> !DumpObj /d 0000020ce073ca68
Name: System.Windows.Threading.PriorityItem`1[[System.Windows.Threading.DispatcherOperation, WindowsBase]]
MethodTable: 00007ffc1ad4e5e0
EEClass: 00007ffc1adb28a0
Size: 64(0x40) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_MSIL\WindowsBase\v4.0_4.0.0.0__31bf3856ad364e35\WindowsBase.dll
Fields:
MT Field Offset Type VT Attr Value Name
00007ffc2b4da238 400123a 8 System.__Canon 0 instance 0000020ce073c898 _data
...
0:000> !DumpObj /d 0000020ce073c840
Name: System.Action
MethodTable: 00007ffc2b55aff0
EEClass: 00007ffc2b665440
Size: 64(0x40) 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
00007ffc2b4d5dd8 40002f3 8 System.Object 0 instance 0000020c4ba28050 _target
00007ffc2b4d5dd8 40002f4 10 System.Object 0 instance 0000000000000000 _methodBase
00007ffc2b5531f8 40002f5 18 System.IntPtr 1 instance 7ffbcfb85b10 _methodPtr
...
0:000> !U 7ffbcfb85b10
Unmanaged code
00007ffb`cfb85b10 e9db38e700 jmp 00007ffb`d09f93f0
00007ffb`cfb85b15 5f pop rdi
00007ffb`cfb85b16 61 ???
00007ffb`cfb85b17 0040dc add byte ptr [rax-24h],al
00007ffb`cfb85b1a c8cffb7f enter 0FBCFh,7Fh
00007ffb`cfb85b1e 0000 add byte ptr [rax],al
00007ffb`cfb85b20 e80bea555f call clr!PrecodeFixupThunk (00007ffc`2f0e4530)
00007ffb`cfb85b25 5e pop rsi
00007ffb`cfb85b26 0000 add byte ptr [rax],al
00007ffb`cfb85b28 68e1c8cffb push 0FFFFFFFFFBCFC8E1h
0:000> !U 00007ffb`d09f93f0
Normal JIT generated code
WpfApp.ViewModel.CalculatedIsocenterShiftViewModel.<UpdateLineGraph>b__93_0()
Begin 00007ffbd09f93f0, size f54
>>> 00007ffb`d09f93f0 55 push rbp
...從卦中可以看到有一個 <UpdateLineGraph>b__93_0 方法,看樣子這是一個匿名方法,接下來用 ilspy 打開觀察源代碼,截圖如下:
圖片
從卦中的代碼看,尼瑪,這是兵家大忌哈。。。居然讓UI線程做什么復雜的業務邏輯,這怎么不讓 UI線程 累死。。。
為了佐證,可以使用 ~*e !clrstack 觀察此時的各個線程棧,可以發現目前有兩個線程正在通過 Dispatcher 給UI發通知并等待UI線程響應,截圖如下:
圖片
到這里基本就真相大白了,這位朋友應該是高頻的往UI打數據(畫圖),導致軟件卡死。
三、總結
這次卡死事故是這位朋友犯了兵家大忌,UI線程只用來更新UI,不要將復雜的業務邏輯丟給UI去做。





































