一：背景
1. 講故事
前幾天有位朋友找到我，說他的窗體程式有卡死現象，讓我幫忙看下怎麼回事，解決這種問題就需要在卡死的時候抓一個dump下來，拿到dump之後就可以分析了。
二：為什麼會卡死
1. 觀察主執行緒
窗體程式的卡死，需要觀察主執行緒此時正在做什麼，可以用 !clrstack 命令觀察。
0:000:x86> !clrstack
OS Thread Id: 0x4a08 (0)
Child SP IP Call Site
012fe784 0000002b [HelperMethodFrame_1OBJ: 012fe784] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
012fe868 7115d952 System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 243]
012fe880 7115d919 System.Threading.WaitHandle.WaitOne(Int32, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 194]
012fe894 711e89bf System.Threading.WaitHandle.WaitOne(Int32) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 220]
012fe89c 6fb186b8 System.Threading.ReaderWriterLockSlim.WaitOnEvent(System.Threading.EventWaitHandle, UInt32 ByRef, TimeoutTracker, EnterLockType)
012fe8e0 6fb17892 System.Threading.ReaderWriterLockSlim.TryEnterReadLockCore(TimeoutTracker)
012fe920 6fb17562 System.Threading.ReaderWriterLockSlim.TryEnterReadLock(TimeoutTracker)
012fe94c 0325f49f xxx.QuyitpjK0dXKR6IyqH(System.Object)
012fe964 0325ee8a xxx.RWAutoLock..ctor(System.Threading.ReaderWriterLockSlim, Boolean)
...
從卦中的執行緒棧資料來看，貌似是卡在一個讀寫鎖TryEnterReadLock 上，根據讀寫鎖的規則，必然有人執行了一個 WriteLock 並且出不來，接下來就是尋找持有這個 lock 的執行緒。
2. 到底誰在持有
如果是 lock ，相信很多朋友都知道用 !syncblk 命令，那讀寫鎖用什麼命令呢？說實話我也搞不清楚,只能先挖挖 ReaderWriterLockSlim 類本身，看看有沒有什麼新發現。
0:000:x86> !DumpObj /d 03526f38
Name: System.Threading.ReaderWriterLockSlim
MethodTable: 6f947428
EEClass: 6f9a92dc
Size: 72(0x48) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System.Core\v4.0_4.0.0.0__b77a5c561934e089\System.Core.dll
Fields:
MT Field Offset Type VT Attr Value Name
70da878c 40004aa 38 System.Boolean 1 instance 0 _fIsReentrant
6f92fa28 40004ab 3c ...LockSlim+SpinLock 1 instance 03526f74 _spinLock
70dfba4c 40004ac 1c System.UInt32 1 instance 20 _numWriteWaiters
70dfba4c 40004ad 20 System.UInt32 1 instance 1 _numReadWaiters
70dfba4c 40004ae 24 System.UInt32 1 instance 0 _numWriteUpgradeWaiters
70dfba4c 40004af 28 System.UInt32 1 instance 0 _numUpgradeWaiters
6f93d764 40004b0 39 System.Byte 1 instance 0 _waiterStates
70da42a8 40004b1 2c System.Int32 1 instance -1 _upgradeLockOwnerId
70da42a8 40004b2 30 System.Int32 1 instance 11 _writeLockOwnerId
70da6924 40004b3 c ...g.EventWaitHandle 0 instance 034844d0 _writeEvent
70da6924 40004b4 10 ...g.EventWaitHandle 0 instance 042a69c8 _readEvent
70da6924 40004b5 14 ...g.EventWaitHandle 0 instance 00000000 _upgradeEvent
70da6924 40004b6 18 ...g.EventWaitHandle 0 instance 00000000 _waitUpgradeEvent
70da150c 40004b8 4 System.Int64 1 instance 367 _lockID
70da878c 40004ba 3a System.Boolean 1 instance 0 _fUpgradeThreadHoldingRead
70dfba4c 40004bc 34 System.UInt32 1 instance 3221225472 _owners
70da878c 40004c2 3b System.Boolean 1 instance 0 _fDisposed
70da42a8 40004a9 4dc System.Int32 1 static 4 ProcessorCount
70da150c 40004b7 4d4 System.Int64 1 static 1882 s_nextLockID
6f942b7c 40004b9 0 ...ReaderWriterCount 0 TLstatic t_rwc
結合原始碼分析，發現上面的 _writeLockOwnerId=11 就是持有鎖的執行緒ID，找到持有執行緒就好辦了，把這個 managedid=11 轉成 dbgid 再觀察。
0:000:x86> !t
13 11 47bc 0a0702c0 1029220 Preemptive 00000000:00000000 01425ed0 0 MTA (Threadpool Worker)
0:013:x86> !clrstack
OS Thread Id: 0x47bc (13)
Child SP IP Call Site
07e4f1ac 0000002b [InlinedCallFrame: 07e4f1ac]
07e4f1a4 09e38597 DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr)
07e4f1ac 09e38334 [InlinedCallFrame: 07e4f1ac] System.Data.SQLite.UnsafeNativeMethods.sqlite3_step(IntPtr)
07e4f1dc 09e38334 System.Data.SQLite.SQLite3.Step(System.Data.SQLite.SQLiteStatement)
07e4f228 09e36fe8 System.Data.SQLite.SQLiteDataReader.NextResult()
07e4f250 09e36ceb System.Data.SQLite.SQLiteDataReader..ctor(System.Data.SQLite.SQLiteCommand, System.Data.CommandBehavior)
07e4f270 09e367ce System.Data.SQLite.SQLiteCommand.ExecuteReader(System.Data.CommandBehavior)
07e4f284 09e36732 System.Data.SQLite.SQLiteCommand.ExecuteNonQuery(System.Data.CommandBehavior)
07e4f2b0 09e366e6 System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
07e4f2bc 09e350dc SqlSugar.AdoProvider.ExecuteCommand(System.String, SqlSugar.SugarParameter[])
07e4f388 13189518 SqlSugar.InsertableProvider`1[[System.__Canon, mscorlib]].ExecuteCommand()
07e4f420 0181ac4a xxx.OperateLog+d__8.MoveNext()
...
0:013:x86> k
CvRegToMachine(x86) conversion failure for 0x14f
X86MachineInfo::SetVal: unknown register 0 requested
# ChildEBP RetAddr
00 07e4ede0 76c9ad10 ntdll_76ed0000!NtFlushBuffersFile+0xc
01 07e4ede0 6b27af8c KERNELBASE!FlushFileBuffers+0x30
WARNING: Stack unwind information not available. Following frames may be wrong.
02 07e4edf0 6b270256 SQLite_Interop!SI768767362ea03a94+0xf73c
03 07e4ee1c 6b267938 SQLite_Interop!SI768767362ea03a94+0x4a06
04 07e4ee38 6b2599e1 SQLite_Interop!SI83d1cf4976f57337+0x84c8
05 07e4ee80 6b25902b SQLite_Interop!SIa3401e98cbad673e+0x3201
06 07e4ee98 6b25258c SQLite_Interop!SIa3401e98cbad673e+0x284b
07 07e4f168 6b255a05 SQLite_Interop!SI327cfc7a6b1fd1fb+0x633c
08 07e4f19c 09e38597 SQLite_Interop!SI9c6d7cd7b7d38055+0x255
結合卦中的讀寫資訊，大概知道了原來是用寫鎖來寫sqlite，後者卡在緩衝區重新整理函式 NtFlushBuffersFile 上，方法簽名如下：
NTSTATUS NtFlushBuffersFile(
HANDLE FileHandle,
IO_STATUS_BLOCK *IoStatusBlock
);
有些朋友可能想看一下到底怎麼寫的，那就簡單的反編譯一下程式碼：
到這裡基本就搞清楚了，由於 13號 執行緒持有了 寫鎖，導致主執行緒要用讀鎖操作 sqlite 時進行了長時間等待。
解決辦法就比較簡單了，主執行緒儘可能的只做UI更新的操作，不要讓他觸發各類鎖，否則就有等鎖的機率發生。
3. NtFlushBuffersFile 怎麼了
有些朋友可能要問為什麼 NtFlushBuffersFile 函式會卡死不返回，要想找到這個答案，需要看下反彙編。
0:013:x86> uf ntdll_76ed0000!NtFlushBuffersFile
ntdll_76ed0000!NtFlushBuffersFile:
76f41ad0 b84b000000 mov eax,4Bh
76f41ad5 ba7071f576 mov edx,offset ntdll_76ed0000!Wow64SystemServiceCall (76f57170)
76f41ada ffd2 call edx
76f41adc c20800 ret 8
0:013:x86> u 76F57170h
ntdll_76ed0000!Wow64SystemServiceCall:
76f57170 ff252892ff76 jmp dword ptr [ntdll_76ed0000!Wow64Transition (76ff9228)]
0:013:x86> u 76ec7000
wow64cpu!KiFastSystemCall:
76ec7000 ea0970ec763300 jmp 0033:76EC7009
76ec7007 0000 add byte ptr [eax],al
76ec7009 41 inc ecx
76ec700a ffa7f8000000 jmp dword ptr [edi+0F8h]
從彙編程式碼看，NtFlushBuffersFile 透過 KiFastSystemCall 進入核心態了，使用者態dump是沒法看核心態的，所以也無法繼續追究下去。
不過也可以看下這個執行緒過往的 GetLastError() 值，可能有些收穫，使用 !gle 命令。
0:013:x86> !gle
LastErrorValue: (Win32) 0x26 (38) - <Unable to get error code text>
LastStatusValue: (NTSTATUS) 0xc0000008 - <Unable to get error code text>
根據上面的狀態碼，去msdn上搜一下具體資訊。
從錯誤說明看，可能是這個sqlite檔案有什麼問題，又是控制程式碼無效，又是讀到頭了，懷疑是操作sqlite 的時候出現了檔案損壞。
現在回頭看看，如果想對 Sqlite 進行併發讀寫，開啟下 Write-Ahead Logging 模式應該就可以了，不需要在程式裡面進行讀寫控制。
所以最終的建議就是：
- 開啟WAL模式
- 刪掉讀寫控制
三：總結
這次卡死事故還是挺有意思的，熟悉了下 ReaderWriterLockSlim 又對 sqlite 有了一個新的認識。
