記一次 .NET 某教育系統API 異常崩潰分析

一線碼農 發表於 2021-05-03

一:背景

1. 講故事

這篇文章起源於 搬磚隊大佬 的精彩文章 WinDBg定位asp.net mvc專案異常崩潰原始碼位置 ,寫的非常好,不過美中不足的是通覽全文之後,總覺得有那麼一點不過癮,就是沒有把當時拋異常前的引數給找出來。。。這一篇我就試著彌補這個遺憾😁😁😁。

為了能夠讓文章行雲流水,我就按照自己的偵察思路吧,首先看一下現狀:iis上的應用程式崩潰, catch 不到錯誤,windows日誌中只記錄了一個 AccessViolationException 異常,如何分析?

說實話我也是第一次在託管語言 C# 中遇到這種異常,夠奇葩,先看看 MSDN 上的解釋。

記一次 .NET 某教育系統API 異常崩潰分析

好了,先不管奇葩不奇葩,反正有了一份 dump + AccessViolationException,還是可以挖一挖的,老規矩,上windbg說話。

二: windbg 分析

1. 尋找異常的執行緒

如果是在 異常崩潰 的時候抓的dump,一般來說這個異常會掛在這個執行執行緒上,不相信的話,可以看看dump。


0:0:037> !t
ThreadCount:      9
UnstartedThread:  0
BackgroundThread: 9
PendingThread:    0
DeadThread:       0
Hosted Runtime:   no
                                                                         Lock  
       ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
   8    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 0ebee9dc
  38    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 sections in file
section 0 - VA=2000, VASize=d8d74, FileAddr=200, FileSize=d8e00
section 1 - VA=dc000, VASize=318, FileAddr=d9000, FileSize=400
section 2 - VA=de000, VASize=c, FileAddr=d9400, FileSize=200

有了 2.dll ,接下來就可以用 ILSPY 看一看原始碼。

記一次 .NET 某教育系統API 異常崩潰分析

從原始碼上看也都是一些中規中矩的操作,沒啥特別的地方,既然寫法上沒問題,我也只能懷疑是某些資料方面出了問題,接下來準備挖一挖 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 提取執行緒棧上的所有引數,如下圖所示:

記一次 .NET 某教育系統API 異常崩潰分析

真是悲劇,由於異常的丟擲搗毀了執行緒呼叫棧,尼瑪,也就是說呼叫棧上的 區域性變數 + 方法引數 都被銷燬了,這該如何是好呀?好想哭😭😭😭。

在迷茫了一段時間後,突然靈光一現,對,雖然呼叫棧被搗毀了,但 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.DateTime
    var isDateTime = output.First().indexOf("System.DateTime") > -1;

    if (isDateTime) return getFormatDate(address);

    output = output.Skip(5).First().replace("String:      ", "");

    return output;
}

function getFormatDate(address) {

    //16hex
    var dtstr = ".printf \"%02X%02X\",poi(" + address + "+0x8),poi(" + address + "+0x4);";

    //10hex
    var 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:       0eb10e08

String:      update xxx  set a=:a, b=:b, c=:c where info_id = :info_id

a -> '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.dll

info_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() 之後居然是以格式化方式顯示的,如下圖所示:

記一次 .NET 某教育系統API 異常崩潰分析

如果想要去掉這種格式化,需要在 ToString() 中配一個 None 列舉,哈哈,就是這麼出乎意料 😓😓😓 。

記一次 .NET 某教育系統API 異常崩潰分析

三:總結

總的來說,我覺得這是 OleDbCommand 的一個bug,既然是做引數化,就算我把 💩 投下去了,你也要給我正確入庫,不是嘛? 其次從分析結果看,知道了這種異常的呼叫堆疊,解決起來也是非常容易的,使用日誌記錄下當時的 OleDbCommand 就可以了,使用 script 暴力搜尋那也是萬不得已的事情😓😓😓, 最後感謝 搬磚隊大佬 的精彩文章和dump。

更多高質量乾貨:參見我的 GitHub: dotnetfly

圖片名稱