记一次 .NET 某工控电池检测系统 卡死分析

二元九点九元店

一：背景

1. 讲故事

前几天有位朋友找到我，说他的窗体程序有卡死现象，让我帮忙看下怎么回事，解决这种问题就需要在卡死的时候抓一个dump下来，拿到dump之后就可以分析了。
二：为什么会卡死

1. 观察主线程

窗体程序的卡死，需要观察主线程此时正在做什么，可以用 !clrstack 命令观察。

1. 0:000:x86> !clrstack
2. OS Thread Id: 0x4a08 (0)
3. Child SP       IP Call Site
4. 012fe784 0000002b [HelperMethodFrame_1OBJ: 012fe784] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
5. 012fe868 7115d952 System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 243]
6. 012fe880 7115d919 System.Threading.WaitHandle.WaitOne(Int32, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 194]
7. 012fe894 711e89bf System.Threading.WaitHandle.WaitOne(Int32) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 220]
8. 012fe89c 6fb186b8 System.Threading.ReaderWriterLockSlim.WaitOnEvent(System.Threading.EventWaitHandle, UInt32 ByRef, TimeoutTracker, EnterLockType)
9. 012fe8e0 6fb17892 System.Threading.ReaderWriterLockSlim.TryEnterReadLockCore(TimeoutTracker)
10. 012fe920 6fb17562 System.Threading.ReaderWriterLockSlim.TryEnterReadLock(TimeoutTracker)
11. 012fe94c 0325f49f xxx.QuyitpjK0dXKR6IyqH(System.Object)
12. 012fe964 0325ee8a xxx.RWAutoLock..ctor(System.Threading.ReaderWriterLockSlim, Boolean)
13. ...

复制代码

从卦中的线程栈数据来看，貌似是卡在一个读写锁TryEnterReadLock 上，根据读写锁的规则，必然有人执行了一个 WriteLock 并且出不来，接下来就是寻找持有这个 lock 的线程。
2. 到底谁在持有

如果是 lock ，相信很多朋友都知道用 !syncblk 命令，那读写锁用什么命令呢？说实话我也搞不清楚,只能先挖挖 ReaderWriterLockSlim 类本身，看看有没有什么新发现。

1. 0:000:x86> !DumpObj /d 03526f38
2. Name:        System.Threading.ReaderWriterLockSlim
3. MethodTable: 6f947428
4. EEClass:     6f9a92dc
5. Size:        72(0x48) bytes
6. File:        C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System.Core\v4.0_4.0.0.0__b77a5c561934e089\System.Core.dll
7. Fields:
8.       MT    Field   Offset                 Type VT     Attr    Value Name
9. 70da878c  40004aa       38       System.Boolean  1 instance        0 _fIsReentrant
10. 6f92fa28  40004ab       3c ...LockSlim+SpinLock  1 instance 03526f74 _spinLock
11. 70dfba4c  40004ac       1c        System.UInt32  1 instance       20 _numWriteWaiters
12. 70dfba4c  40004ad       20        System.UInt32  1 instance        1 _numReadWaiters
13. 70dfba4c  40004ae       24        System.UInt32  1 instance        0 _numWriteUpgradeWaiters
14. 70dfba4c  40004af       28        System.UInt32  1 instance        0 _numUpgradeWaiters
15. 6f93d764  40004b0       39          System.Byte  1 instance        0 _waiterStates
16. 70da42a8  40004b1       2c         System.Int32  1 instance       -1 _upgradeLockOwnerId
17. 70da42a8  40004b2       30         System.Int32  1 instance       11 _writeLockOwnerId
18. 70da6924  40004b3        c ...g.EventWaitHandle  0 instance 034844d0 _writeEvent
19. 70da6924  40004b4       10 ...g.EventWaitHandle  0 instance 042a69c8 _readEvent
20. 70da6924  40004b5       14 ...g.EventWaitHandle  0 instance 00000000 _upgradeEvent
21. 70da6924  40004b6       18 ...g.EventWaitHandle  0 instance 00000000 _waitUpgradeEvent
22. 70da150c  40004b8        4         System.Int64  1 instance 367 _lockID
23. 70da878c  40004ba       3a       System.Boolean  1 instance        0 _fUpgradeThreadHoldingRead
24. 70dfba4c  40004bc       34        System.UInt32  1 instance 3221225472 _owners
25. 70da878c  40004c2       3b       System.Boolean  1 instance        0 _fDisposed
26. 70da42a8  40004a9      4dc         System.Int32  1   static        4 ProcessorCount
27. 70da150c  40004b7      4d4         System.Int64  1   static 1882 s_nextLockID
28. 6f942b7c  40004b9        0 ...ReaderWriterCount  0 TLstatic  t_rwc

复制代码

结合源码分析，发现上面的 _writeLockOwnerId=11 就是持有锁的线程ID，找到持有线程就好办了，把这个 managedid=11 转成 dbgid 再观察。

1. 0:000:x86> !t
3.   13   11 47bc 0a0702c0   1029220 Preemptive  00000000:00000000 01425ed0 0     MTA (Threadpool Worker)
5. 0:013:x86> !clrstack
6. OS Thread Id: 0x47bc (13)
7. Child SP       IP Call Site
8. 07e4f1ac 0000002b [InlinedCallFrame: 07e4f1ac]
9. 07e4f1a4 09e38597 DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr)
10. 07e4f1ac 09e38334 [InlinedCallFrame: 07e4f1ac] System.Data.SQLite.UnsafeNativeMethods.sqlite3_step(IntPtr)
11. 07e4f1dc 09e38334 System.Data.SQLite.SQLite3.Step(System.Data.SQLite.SQLiteStatement)
12. 07e4f228 09e36fe8 System.Data.SQLite.SQLiteDataReader.NextResult()
13. 07e4f250 09e36ceb System.Data.SQLite.SQLiteDataReader..ctor(System.Data.SQLite.SQLiteCommand, System.Data.CommandBehavior)
14. 07e4f270 09e367ce System.Data.SQLite.SQLiteCommand.ExecuteReader(System.Data.CommandBehavior)
15. 07e4f284 09e36732 System.Data.SQLite.SQLiteCommand.ExecuteNonQuery(System.Data.CommandBehavior)
16. 07e4f2b0 09e366e6 System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
17. 07e4f2bc 09e350dc SqlSugar.AdoProvider.ExecuteCommand(System.String, SqlSugar.SugarParameter[])
18. 07e4f388 13189518 SqlSugar.InsertableProvider`1[[System.__Canon, mscorlib]].ExecuteCommand()
19. 07e4f420 0181ac4a xxx.OperateLog+d__8.MoveNext()
20. ...
22. 0:013:x86> k
23. CvRegToMachine(x86) conversion failure for 0x14f
24. X86MachineInfo::SetVal: unknown register 0 requested
25. # ChildEBP RetAddr      
26. 00 07e4ede0 76c9ad10     ntdll_76ed0000!NtFlushBuffersFile+0xc
27. 01 07e4ede0 6b27af8c     KERNELBASE!FlushFileBuffers+0x30
28. WARNING: Stack unwind information not available. Following frames may be wrong.
29. 02 07e4edf0 6b270256     SQLite_Interop!SI768767362ea03a94+0xf73c
30. 03 07e4ee1c 6b267938     SQLite_Interop!SI768767362ea03a94+0x4a06
31. 04 07e4ee38 6b2599e1     SQLite_Interop!SI83d1cf4976f57337+0x84c8
32. 05 07e4ee80 6b25902b     SQLite_Interop!SIa3401e98cbad673e+0x3201
33. 06 07e4ee98 6b25258c     SQLite_Interop!SIa3401e98cbad673e+0x284b
34. 07 07e4f168 6b255a05     SQLite_Interop!SI327cfc7a6b1fd1fb+0x633c
35. 08 07e4f19c 09e38597     SQLite_Interop!SI9c6d7cd7b7d38055+0x255

复制代码

结合卦中的读写信息，大概知道了原来是用写锁来写sqlite，后者卡在缓冲区刷新函数 NtFlushBuffersFile 上，方法签名如下：

1. NTSTATUS NtFlushBuffersFile(
2.   HANDLE  FileHandle,
3.   IO_STATUS_BLOCK *IoStatusBlock
4. );

复制代码

有些朋友可能想看一下到底怎么写的，那就简单的反编译一下代码：

到这里基本就搞清楚了，由于 13号 线程持有了 写锁，导致主线程要用读锁操作 sqlite 时进行了长时间等待。
解决办法就比较简单了，主线程尽可能的只做UI更新的操作，不要让他触发各类锁，否则就有等锁的概率发生。
3. NtFlushBuffersFile 怎么了

有些朋友可能要问为什么 NtFlushBuffersFile 函数会卡死不返回，要想找到这个答案，需要看下反汇编。

1. 0:013:x86> uf ntdll_76ed0000!NtFlushBuffersFile
2. ntdll_76ed0000!NtFlushBuffersFile:
3. 76f41ad0 b84b000000      mov     eax,4Bh
4. 76f41ad5 ba7071f576      mov     edx,offset ntdll_76ed0000!Wow64SystemServiceCall (76f57170)
5. 76f41ada ffd2            call    edx
6. 76f41adc c20800          ret     8
8. 0:013:x86> u 76F57170h
9. ntdll_76ed0000!Wow64SystemServiceCall:
10. 76f57170 ff252892ff76    jmp     dword ptr [ntdll_76ed0000!Wow64Transition (76ff9228)]
12. 0:013:x86> u 76ec7000
13. wow64cpu!KiFastSystemCall:
14. 76ec7000 ea0970ec763300  jmp     0033:76EC7009
15. 76ec7007 0000            add     byte ptr [eax],al
16. 76ec7009 41              inc     ecx
17. 76ec700a ffa7f8000000    jmp     dword ptr [edi+0F8h]

复制代码

从汇编代码看，NtFlushBuffersFile 通过 KiFastSystemCall 进入内核态了，用户态dump是没法看内核态的，所以也无法继续追究下去。
不过也可以看下这个线程过往的 GetLastError() 值，可能有些收获，使用 !gle 命令。

1. 0:013:x86> !gle
2. LastErrorValue: (Win32) 0x26 (38) - <Unable to get error code text>
3. LastStatusValue: (NTSTATUS) 0xc0000008 - <Unable to get error code text>

复制代码

根据上面的状态码，去msdn上搜一下具体信息。

从错误说明看，可能是这个sqlite文件有什么问题，又是句柄无效，又是读到头了，怀疑是操作sqlite 的时候出现了文件损坏。
现在回头看看，如果想对 Sqlite 进行并发读写，开启下 Write-Ahead Logging 模式应该就可以了，不需要在程序里面进行读写控制。

所以最终的建议就是：

• 开启WAL模式
  
• 删掉读写控制
  

三：总结

这次卡死事故还是挺有意思的，熟悉了下 ReaderWriterLockSlim 又对 sqlite 有了一个新的认识。

来源:https://www.cnblogs.com/huangxincheng/archive/2023/11/13/17829307.html
免责声明：由于采集信息均来自互联网，如果侵犯了您的权益，请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容，谢谢合作！