记一次 .NET 某教育系统 异常崩溃分析
一:背景
1. 講故事
這篇文章起源于 搬磚隊大佬 的精彩文章 WinDBg定位asp.net mvc項目異常崩潰源碼位置 ,寫的非常好,不過美中不足的是通覽全文之后,總覺得有那么一點不過癮,就是沒有把當時拋異常前的參數給找出來。。。這一篇我就試著彌補這個遺憾????????????。
為了能夠讓文章行云流水,我就按照自己的偵察思路吧,首先看一下現狀:iis上的應用程序崩潰, catch 不到錯誤,windows日志中只記錄了一個 AccessViolationException 異常,如何分析?
說實話我也是第一次在托管語言 C# 中遇到這種異常,夠奇葩,先看看 MSDN 上的解釋。
好了,先不管奇葩不奇葩,反正有了一份 dump + AccessViolationException,還是可以挖一挖的,老規矩,上windbg說話。
二:windbg 分析
1. 尋找異常的線程
如果是在 異常崩潰 的時候抓的dump,一般來說這個異常會掛在這個執行線程上,不相信的話,可以看看dump。
0:0:037>?!t ThreadCount:??????9 UnstartedThread:??0 BackgroundThread:?9 PendingThread:????0 DeadThread:???????0 Hosted?Runtime:???noLock??ID?OSID?ThreadOBJ????State?GC?Mode?????GC?Alloc?Context??Domain???Count?Apt?Exception8????1?2188?019da830?????28220?Preemptive??10C08398:00000000?01a02bd8?0?????Ukn?29????2?36b8?025d7738?????2b220?Preemptive??00000000:00000000?01a02bd8?0?????MTA?(Finalizer)?31????3?1c6c?0260b568???102a220?Preemptive??00000000:00000000?01a02bd8?0?????MTA?(Threadpool?Worker)?32????4?315c?02616678?????21220?Preemptive??00000000:00000000?01a02bd8?0?????Ukn?34????6?31c0?026180e0???1020220?Preemptive??00000000:00000000?01a02bd8?0?????Ukn?(Threadpool?Worker)?35????7?1274?02618628???1029220?Preemptive??069745A0:00000000?01a02bd8?0?????MTA?(Threadpool?Worker)?37????8?2484?02617108???1029220?Preemptive??0EBFFB18:00000000?01a02bd8?0?????MTA?(Threadpool?Worker)?System.AccessViolationException?0ebee9dc38????9?2234?026156a0???1029220?Preemptive??0AAED5CC:00000000?01a02bd8?0?????MTA?(Threadpool?Worker)?39???10?3858?02617b98???1029220?Preemptive??0CB7BEE0:00000000?01a02bd8?0?????MTA?(Threadpool?Worker)?上面的第37號線程清楚的記錄了異常 System.AccessViolationException,后面還跟了一個異常對象的地址 0ebee9dc ,接下來就可以用 !do 給打印出來。
0:0:037>?!do?0ebee9dc Name:????????System.AccessViolationException MethodTable:?6fc1bf4c EEClass:?????6f926bec Size:????????96(0x60)?bytes File:????????C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll Fields:MT????Field???Offset?????????????????Type?VT?????Attr????Value?Name 6fc146a4??4000005???????10????????System.String??0?instance?0ebf02f0?_message 6fc1be98??4000006???????14?...tions.IDictionary??0?instance?00000000?_data 6fc146a4??400000c???????2c????????System.String??0?instance?0ebfd24c?_remoteStackTraceString這個 Exception 上面有很多的屬性,比如最后一行的 _remoteStackTraceString 顯示的就是異常堆棧信息,接下來我再給 do 一下。
0:0:037>?!do?0ebfd24c Name:????????System.String MethodTable:?6fc146a4 EEClass:?????6f8138f0 Size:????????10444(0x28cc)?bytes File:????????C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll String:?????????在?System.Data.Common.UnsafeNativeMethods.ICommandText.Execute(IntPtr?pUnkOuter,?Guid&?riid,?tagDBPARAMS?pDBParams,?IntPtr&?pcRowsAffected,?Object&?ppRowset)在?System.Data.OleDb.OleDbCommand.ExecuteCommandTextForMultpleResults(tagDBPARAMS?dbParams,?Object&?executeResult)在?System.Data.OleDb.OleDbCommand.ExecuteCommandText(Object&?executeResult)在?System.Data.OleDb.OleDbCommand.ExecuteCommand(CommandBehavior?behavior,?Object&?executeResult)在?System.Data.OleDb.OleDbCommand.ExecuteReaderInternal(CommandBehavior?behavior,?String?method)在?System.Data.OleDb.OleDbCommand.ExecuteNonQuery()在?xxx.Model.xxx.getOneData(OleDbCommand?comm)在?xxx.Model.xxx.getOtherDataSource(List`1?keys,?Dictionary`2?data)在?xxx.Controllers.xxxOtherController.Post(JObject?json)在?System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass10.<GetExecutor>b__9(Object?instance,?Object[]?methodParameters)在?System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.Execute(Object?instance,?Object[]?arguments)在?System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext?controllerContext,?IDictionary`2?arguments,?CancellationToken?cancellationToken)我去,原來是執行數據庫的時候拋出的 AccessViolationException,哈哈,有點意思,究竟是個什么樣的神操作能搞出這個異常?好,接下來我就來挖一下 getOneData() 方法到底干了什么?
2.尋找問題代碼 getOneData()
要想找到 getOneData() 的源碼,還是老規矩,使用 !name2ee + !savemodule 導出。
0:0:037>?!name2ee?*!xxx.Model.xxx.getOneData -------------------------------------- Module:??????1b9679c0 Assembly:????xxx.dll Token:???????06000813 MethodDesc:??0149faec Name:????????xxx.Model.xxx.getOneData(System.Data.OleDb.OleDbCommand) JITTED?Code?Address:?1ede0050 --------------------------------------0:0:037>?!savemodule?1b9679c0?E:\dumps\2.dll 3?ps?in?file p?0?-?VA=2000,?VASize=d8d74,?FileAddr=200,?FileSize=d8e00 p?1?-?VA=dc000,?VASize=318,?FileAddr=d9000,?FileSize=400 p?2?-?VA=de000,?VASize=c,?FileAddr=d9400,?FileSize=200有了 2.dll ,接下來就可以用 ILSPY 看一看源碼。
從源碼上看也都是一些中規中矩的操作,沒啥特別的地方,既然寫法上沒問題,我也只能懷疑是某些數據方面出了問題,接下來準備挖一挖 OleDbCommand。
3. 從線程棧上提取 OleDbCommand 對象
玩過 ADO.NET 的都知道,最后的 sql + parameters 都是藏在 OleDbCommand 上的,參考代碼如下:
public?sealed?class?OleDbCommand?:?DbCommand,?ICloneable,?IDbCommand,?IDisposable {public?override?string?CommandText?{?get;?set;?}public?new?OleDbParameterCollection?Parameters{get{OleDbParameterCollection?oleDbParameterCollection?=?_parameters;if?(oleDbParameterCollection?==?null){oleDbParameterCollection?=?(_parameters?=?new?OleDbParameterCollection());}return?oleDbParameterCollection;}} }所以目標很明確,就是把 CommandText + Parameters 給挖出來,說干就干,用 !clrstack -a 提取線程棧上的所有參數,如下圖所示:
真是悲劇,由于異常的拋出搗毀了線程調用棧,尼瑪,也就是說調用棧上的 局部變量 + 方法參數 都被銷毀了,這該如何是好呀?好想哭????????????。
在迷茫了一段時間后,突然靈光一現,對,雖然調用棧被搗毀了,但 OleDbCommand 是引用類型啊,棧地址沒了就沒了,OleDbCommand 本尊肯定還是在熱乎的 gen0 上,畢竟也是剛拋出來的異常,這時候 GC 還在打呼嚕,肯定不會回收它的,哈哈,突然又充滿能量了。
4. 從托管堆中尋找 OleDbCommand
要想在托管堆上找 OleDbCommand 的話,使用如下命令:!dumpheap -type OleDbCommand 即可。
||0:0:037>?!dumpheap?-type?OleDbCommand?Address???????MT?????Size 02a8393c?6c74a6a8???????84????? 02bc280c?6c74a6a8???????84????? 02bd98dc?6c74a6a8???????84????? 02be1d74?6c74a6a8???????84????? 02be3c68?6c74a6a8???????84????? 02be5b3c?6c74a6a8???????84????? 0696f978?6c74a6a8???????84????? 0a94ea54?6c74a6a8???????84????? 0a9678b8?6c74a6a8???????84????? 0a96a5a0?6c74a6a8???????84????? 0aabefe4?6c74a6a8???????84????? 0eb10e08?6c74a6a8???????84?????Statistics:MT????Count????TotalSize?Class?Name 6c74a6a8???????12?????????1008?System.Data.OleDb.OleDbCommand Total?12?objects還不錯,托管堆上只有 12 個 OleDbCommand,說明這程序也是剛起來沒溜兩圈就掛掉了,接下來要做的事就是逐個排查里面的 Sql + Parameter 是否有異常,用人肉去檢查,能把眼睛給弄瞎,所以得把這臟活累活留給 script 去實現,為此我花了一個小時寫了一個腳本,都差點寫睡著了????????????。
"use?strict";function?initializeScript()?{return?[new?host.apiVersionSupport(1,?7)]; }function?invokeScript()?{//獲取所有?oledbComamand?對象var?output?=?exec("!dumpheap?-type?System.Data.OleDb.OleDbCommand?-short");for?(var?line?of?output)?{showOleDb(line);log("------------------------------------------------------------------------");} }//遍歷oledb function?showOleDb(oledb)?{log("oledb:???????"?+?oledb);showsql(oledb);showparameters(oledb); }//show?sql function?showsql(oledb)?{var?command?=?"!do?-nofields?poi("?+?oledb?+?"+0x10)";var?output?=?exec(command).Skip(5);for?(var?line?of?output)?{log(line);} }//show?parameters function?showparameters(oledb)?{var?address?=?"poi(poi(poi("?+?oledb?+?"+0x1c)+0x8)+0x4)"var?arrlen?=?"poi("?+?address?+?"+0x4)";var?command?=?"!da?-nofields?-details?"?+?address;//var?str?=?"";var?output?=?exec(command).Where(k?=>?k.indexOf("[")?==?0).Select(k?=>?k.split('?')[1]).Where(k?=>?k?!=?"null").Select(k?=>?k);for?(var?line?of?output)?{var?name?=?showparamname(line);var?value?=?showparamvalue(line);log(name?+?"?->?"?+?value);} }//show?parametername function?showparamname(param)?{var?command?=?"!do?-nofields?poi("?+?param?+?"+0xc)";var?output?=?exec(command);output?=?output.Skip(5).First().replace("String:??????",?"");return?output; }//show?paramtervalue function?showparamvalue(param,?offset)?{//第一步:?判斷是否為引用類型var?address?=?"poi("?+?param?+?"+0x14)";var?isGtZero?=?parseInt(exec(".printf?\"%d\","?+?address).First())?>?0;if?(!isGtZero)?return?"0";var?command?=?"!do?-nofields?"?+?address;var?output?=?exec(command);//第二步:?判斷是否為?System.DateTimevar?isDateTime?=?output.First().indexOf("System.DateTime")?>?-1;if?(isDateTime)?return?getFormatDate(address);output?=?output.Skip(5).First().replace("String:??????",?"");return?output; }function?getFormatDate(address)?{//16hexvar?dtstr?=?".printf?\"%02X%02X\",poi("?+?address?+?"+0x8),poi("?+?address?+?"+0x4);";//10hexvar?num?=?parseInt("0x"?+?exec(dtstr).First(),?16);var?command?=?"!filetime?((0n"?+?num?+?"?&?0x3fffffffffffffff)?-?0n504911519999995142)";var?time?=?exec(command).First().split("(")[0].trim();return?time; }function?log(instr)?{host.diagnostics.debugLog("\n"?+?instr?+?"\n"); }function?exec(str)?{return?host.namespace.Debugger.Utility.Control.ExecuteCommand(str); }簡單說一下,上面的 poi 表示取地址上的值,這個值可能是數字,也可能是引用地址,接下來把腳本跑起來, 由于這信息太敏感了,只能虛擬化了哈。
------------------------------------------------------------------------oledb:???????0eb10e08String:??????update?xxx??set?a=:a,?b=:b,?c=:c?where?info_id?=?:info_ida?->?'xxx'b?->?'yyy'c?->?File:????????C:\Windows\Microsoft.NET\Framework\v4.0.30319\Temporary?ASP.NET?Files\collegeappxy\e05a2cb1\4405de9e\assembly\dl3\d914f432\c1375f08_c05cd201\Newtonsoft.Json.dllinfo_id?->?1在 1s 的等待后,終于發現上面這條 sql 的參數化 c 出了問題,因為它是一個 Newtonsoft.Json.dll 的 File,真奇葩,稍微修改一下腳本把這個參數的 address 找出來。
||0:0:037>?!do?-nofields?poi(0eb9ba40+0x14) Name:????????Newtonsoft.Json.Linq.JObject MethodTable:?1c600d98 EEClass:?????1c5f31d0 CCW:?????????1bbd0020 Size:????????68(0x44)?bytes File:????????C:\Windows\Microsoft.NET\Framework\v4.0.30319\Temporary?ASP.NET?Files\collegeappxy\e05a2cb1\4405de9e\assembly\dl3\d914f432\c1375f08_c05cd201\Newtonsoft.Json.dll到此基本確定是因為把 JObject 放入了參數化導致了異常的發生,為此我還特意查了下 JObject ,一個挺有意思的玩意,將它 ToString() 之后居然是以格式化方式顯示的,如下圖所示:
如果想要去掉這種格式化,需要在 ToString() 中配一個 None 枚舉,哈哈,就是這么出乎意料 ???????????? 。
三:總結
總的來說,我覺得這是 OleDbCommand 的一個bug,既然是做參數化,就算我把 ???? 投下去了,你也要給我正確入庫,不是嘛?其次從分析結果看,知道了這種異常的調用堆棧,解決起來也是非常容易的,使用日志記錄下當時的 OleDbCommand 就可以了,使用 script 暴力搜索那也是萬不得已的事情????????????, 最后感謝 搬磚隊大佬 的精彩文章和dump。
END
工作中的你,是否已遇到 ...?
1. CPU爆高
2. 內存暴漲
3. 資源泄漏
4. 崩潰死鎖
5. 程序呆滯
等緊急事件,全公司都指望著你能解決...? 危難時刻才能展現你的技術價值,作為專注于.NET高級調試的技術博主,歡迎微信搜索: 一線碼農聊技術,免費協助你分析Dump文件,希望我能將你的踩坑經驗分享給更多的人。
總結
以上是生活随笔為你收集整理的记一次 .NET 某教育系统 异常崩溃分析的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: ML.NET 示例:图像分类模型训练-首
- 下一篇: [Abp vNext 源码分析] - 1