Windows卡死问题分析

1. 背景

近期在客户的电脑上面部署软件的时候，出现了系统卡死的情况；抓取卡死dump，看到信息如下：

0: kd> !targetinfo
Windows 10 Built by: 17763.1.amd64fre.rs5_release.180914-1434,
Kernel debug session
Crash Time:               Fri Oct 29 21:53:36 2021
System Uptime:             0 days 0:03:15
Version:                   10.0
Processors:                4 proc (F/M/S Vendor)>0 6/15/1 GenuineIntel1 6/15/1 GenuineIntel2 6/15/1 GenuineIntel3 6/15/1 GenuineIntel

Windows10 x64的系统，下面我们分析一下具体原因。

2. 分析

首先，我们看一下Windows有没有普通的死锁情况的发生，如下：

0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks.........
20005 total locks

并没有出现相关的ERESOURCE死锁，也就是说系统层面应该没有形成同步锁的死锁情况。

既然没有形成死锁，难道一个进程一个进程的去分析每个线程的情况吗？这样的话工作量太大了，我们可以先简单看一看IRP的情况，看是否有其他第三方驱动的IRP没有完成导致系统卡住了。

非常幸运的是，我们很快找到了这样一个线程，如下：

0: kd> !thread ffffdf852da91080
THREAD ffffdf852da91080  Cid 2d10.2da4  Teb: 00000008809c5000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertableffff9606fdaa71f0  NotificationEvent
IRP List:ffffdf852ecee010: (0006,0478) Flags: 00000884  Mdl: 00000000
Not impersonating
DeviceMap                 ffffc50739813a80
Owning Process            ffffdf852eab4080       Image:         TMBMSRV.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10266          Ticks: 2246 (0:00:00:35.093)
Context Switch Count      1794           IdealProcessor: 1
UserTime                  00:00:00.343
KernelTime                00:00:00.062
Win32 Start Address 0x00007ffd77ad3dd0
Stack Init ffff9606fdaa7dd0 Current ffff9606fdaa6df0
Base ffff9606fdaa8000 Limit ffff9606fdaa2000 Call 0000000000000000
Priority 9 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
ffff9606`fdaa6e30 fffff807`7fee3967 : ffffdf85`2da91080 00000000`00000000 ffff8480`9efab100 ffffdf85`2e3db040 : nt!KiSwapContext+0x76
ffff9606`fdaa6f70 fffff807`7fee34d9 : 00000000`00000001 ffffdf85`2e3db1b0 ffffdf85`2e3db040 ffffdf85`2d097180 : nt!KiSwapThread+0x297
ffff9606`fdaa7030 fffff807`7fee2260 : ffffdf85`2d097100 00000000`00000000 ffffdf85`00000000 ffff9606`fdaa7141 : nt!KiCommitThreadWait+0x549
ffff9606`fdaa70d0 fffff807`8498dc93 : ffff9606`fdaa71f0 ffffdf85`00000000 00000000`00000000 ffffdf85`2da91000 : nt!KeWaitForSingleObject+0x520
ffff9606`fdaa71a0 fffff807`84983cf3 : 00000000`00000000 ffff9606`fdaa7378 ffff9606`fdaa7378 ffff9606`fdaa7378 : xxxsysdrv+0xdc93
ffff9606`fdaa7230 fffff807`849872bf : ffffdf85`2e36d3c8 ffffdf85`2e36d3c8 ffffdf85`2e36d468 ffffc507`408f3210 : xxxsysdrv+0x3cf3
ffff9606`fdaa7270 fffff807`849860dd : ffffdf85`26330570 ffffc507`3e644b70 00000000`00000000 00000000`00000000 : xxxsysdrv+0x72bf
ffff9606`fdaa7300 fffff80d`8ded442e : ffffdf85`2e36d2e0 ffffdf85`2ecf04e0 00000000`00000000 00002b28`00000000 : xxxsysdrv+0x60dd
ffff9606`fdaa7330 fffff80d`8ded3cf3 : ffffdf85`2ac83800 00000000`00000000 ffffdf85`2cf7c6a8 00000000`00000000 : FLTMGR!FltpPerformPostCallbacks+0x32e
ffff9606`fdaa7400 fffff80d`8ded6291 : ffffdf85`2ecee3f8 ffffdf85`2e36d2e0 00000000`00000008 ffffdf85`2ecee010 : FLTMGR!FltpPassThroughCompletionWorker+0x73
ffff9606`fdaa7470 fffff80d`8df0d559 : ffff9606`fdaa7520 ffffdf85`2ac83800 00000000`000000c0 00000000`00000000 : FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x301
ffff9606`fdaa74e0 fffff807`7fef0109 : ffffdf85`2ac83700 00000000`00000085 00000000`00000000 ffff8480`00000030 : FLTMGR!FltpCreate+0x2f9
ffff9606`fdaa7590 fffff807`7fee90c4 : 00000000`00000000 00000000`00000000 ffffdf85`2ed0c380 fffff807`7fee96d3 : nt!IofCallDriver+0x59
ffff9606`fdaa75d0 fffff807`804724a7 : ffff9606`fdaa7890 00000000`00000085 00000000`00000000 ffffdf85`26e90770 : nt!IoCallDriverWithTracing+0x34
ffff9606`fdaa7620 fffff807`8047a6f9 : ffffdf85`26a5a8f0 ffffdf85`26a5a8c0 ffffdf85`2ca73050 ffffc507`47478701 : nt!IopParseDevice+0x11e7
ffff9606`fdaa7790 fffff807`804792ef : ffffdf85`2ca73000 ffff9606`fdaa79f8 fffff807`00000040 ffffdf85`24ef5ae0 : nt!ObpLookupObjectName+0x719
ffff9606`fdaa7960 fffff807`8053d8a2 : ffffdf85`00000001 00000008`823fe5b8 00000000`00000000 00000000`00004021 : nt!ObOpenObjectByNameEx+0x1df
ffff9606`fdaa7aa0 fffff807`8053cfd8 : 00000008`823fe540 00000000`00100001 00000008`823fe5b8 00000008`823fe5a8 : nt!IopCreateFile+0x822
ffff9606`fdaa7b40 fffff807`80080605 : 00000129`839db6f8 ffffc507`3c007ca0 ffffdf85`2da91080 00000008`823ff538 : nt!NtOpenFile+0x58
ffff9606`fdaa7bd0 00007ffd`a73bf7e4 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KiSystemServiceCopyEnd+0x25 (TrapFrame @ ffff9606`fdaa7c40)
00000008`823fe4e8 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : 0x00007ffd`a73bf7e4

这里是一个文件IO请求，然后minifilter驱动中调用了xxxsysdrv驱动，这个驱动调用nt!KeWaitForSingleObject进入等待似乎一直没有完成，那么这个等待是什么呢？我们反汇编相关代码可以发现如下：

0: kd> u poi(fffff807`84994310)
nt!ExQueueWorkItem:
fffff807`7ffbeb90 48895c2408      mov     qword ptr [rsp+8],rbx
fffff807`7ffbeb95 57              push    rdi
fffff807`7ffbeb96 4883ec30        sub     rsp,30h
fffff807`7ffbeb9a 4863da          movsxd  rbx,edx
fffff807`7ffbeb9d 488bf9          mov     rdi,rcx
fffff807`7ffbeba0 8bd3            mov     edx,ebx
fffff807`7ffbeba2 e879ffffff      call    nt!ExpValidateWorkItem (fffff807`7ffbeb20)
fffff807`7ffbeba7 8bcb            mov     ecx,ebx

应该是在等待一个workitem完成相关事宜，看来是WorkItem一直没有完成导致的，我们看一下Work的响应地方如下：

0: kd> !thread ffffdf8524e92680
THREAD ffffdf8524e92680  Cid 0004.00ac  Teb: 0000000000000000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) KernelMode Non-Alertableffffdf8524e92cc8  Semaphore Limit 0x1
Waiting for reply to ALPC Message ffffc5073f4f0040 : queued at port ffffdf852df88750 : owned by process ffffdf852eab4080
Not impersonating
DeviceMap                 ffffc50739813a80
Owning Process            ffffdf8524e7e040       Image:         System
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10266          Ticks: 2246 (0:00:00:35.093)
Context Switch Count      1135           IdealProcessor: 1
UserTime                  00:00:00.000
KernelTime                00:00:00.046
Win32 Start Address nt!ExpWorkerThread (0xfffff8077ffc01b0)
Stack Init ffff9606fad5bdd0 Current ffff9606fad5a060
Base ffff9606fad5c000 Limit ffff9606fad56000 Call 0000000000000000
Priority 12 BasePriority 12 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
ffff9606`fad5a0a0 fffff807`7fee3967 : ffffc507`3f4f0040 ffffdf85`24e92680 00000000`00000000 ffffdf85`2d9ed080 : nt!KiSwapContext+0x76
ffff9606`fad5a1e0 fffff807`7fee34d9 : ffffdf85`24e92680 00000000`00000000 00000000`0a02717e ffffdf85`2df88750 : nt!KiSwapThread+0x297
ffff9606`fad5a2a0 fffff807`7fee2260 : ffffdf85`2d9ed600 ffff8480`00000000 00000000`00000000 ffff9606`fad5a3b1 : nt!KiCommitThreadWait+0x549
ffff9606`fad5a340 fffff807`7febbb52 : ffffdf85`24e92cc8 00000000`00000011 ffff9606`00000001 00000000`00000000 : nt!KeWaitForSingleObject+0x520
ffff9606`fad5a410 fffff807`8044b196 : 00000000`00000000 ffffdf85`24e92cc8 ffff9606`00000011 ffff9606`fad5ab00 : nt!AlpcpSignalAndWait+0x222
ffff9606`fad5a4b0 fffff807`8044acb5 : ffffdf85`2e60f520 ffffffff`ffffffff ffff9606`fad5a900 ffff9606`fad5ab70 : nt!AlpcpReceiveSynchronousReply+0x56
ffff9606`fad5a510 fffff807`8043df8e : ffffdf85`2e60f520 fffff807`00020000 ffff9606`fad5a900 00000000`00000000 : nt!AlpcpProcessSynchronousRequest+0x3a5
ffff9606`fad5a620 fffff807`8043dede : 00000000`00000000 ffff9606`fad5ab70 00000000`00000000 fffff807`8009fd9d : nt!LpcpRequestWaitReplyPort+0x86
ffff9606`fad5a680 fffff807`80080605 : ffffdf85`24e92680 ffff9606`fad5a740 00000000`00000000 ffffdf85`2e60f520 : nt!NtRequestWaitReplyPort+0x6e
ffff9606`fad5a6c0 fffff807`800730c0 : fffff80d`8ef79f55 01000000`00100000 fffff807`801fe04d 00000000`00000103 : nt!KiSystemServiceCopyEnd+0x25 (TrapFrame @ ffff9606`fad5a6c0)
ffff9606`fad5a858 fffff80d`8ef79f55 : 01000000`00100000 fffff807`801fe04d 00000000`00000103 00000000`00000000 : nt!KiServiceLinkage
ffff9606`fad5a860 fffff80d`8ef7ab29 : ffff9606`fad5ae80 ffff9606`fad5aee0 00000000`00000004 fffff807`00000000 : tmcomm!KmSetCommPortAPIs+0x795
ffff9606`fad5ad90 fffff80d`8ef79782 : ffff9606`fad5ae80 fffff807`8458d500 ffff9606`fad5aee0 fffff807`800112b9 : tmcomm!InitKmLPC+0x23d
ffff9606`fad5ae10 fffff807`8457b8f3 : ffff9606`fad5ae80 fffff807`8458d500 ffff9606`fad5aee0 fffff80d`8efa2e22 : tmcomm!KmCallUmEx+0x26
ffff9606`fad5ae40 fffff807`8457bffd : ffffc507`00000000 00000000`0000000f ffff9606`fad5b160 fffff80d`00000000 : tmactmon+0xb8f3
ffff9606`fad5aee0 fffff807`8457ca07 : ffffdf85`24e92680 ffffc507`39ff3438 00000000`00000000 ffffc507`3c01ca38 : tmactmon+0xbffd
ffff9606`fad5b020 fffff807`8457c7a6 : 00000000`00000000 00000000`00000000 00000000`0000000f ffff9606`fad5b160 : tmactmon+0xca07
ffff9606`fad5b0d0 fffff807`8454b1bb : ffffdf85`263837e8 ffff9606`fad5b3c0 00000000`00000039 ffffc507`47185c70 : tmactmon+0xc7a6
ffff9606`fad5b100 fffff807`8454a64e : ffff9606`fad5b420 ffff9606`fad5b420 ffffdf85`2635ebb0 ffffdf85`00000000 : tmevtmgr!TMEvtCommunicateRoutine+0x2383
ffff9606`fad5b130 fffff807`8044df8a : ffffc507`3e7e6f10 ffff9606`00000000 00000000`000000ac 00000000`00000000 : tmevtmgr!TMEvtCommunicateRoutine+0x1816
ffff9606`fad5b200 fffff807`8047f34b : ffffdf85`24e9cf00 ffff9606`fad5b3a0 00000000`001fffff 00000000`00000240 : nt!ObpCallPreOperationCallbacks+0xfa
ffff9606`fad5b280 fffff807`80527a14 : ffff9606`fad5b830 ffffdf85`2eab4080 00000000`000000ff 00000000`00000000 : nt!ObpCreateHandle+0xa7b
ffff9606`fad5b4c0 fffff807`80527e29 : ffff9606`fad5bae0 00000000`00000000 00000000`00000001 00000000`001fffff : nt!ObOpenObjectByPointer+0x184
ffff9606`fad5b740 fffff807`80526dc3 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!PsOpenProcess+0x289
ffff9606`fad5ba20 fffff807`80080605 : 0f0f0f0f`0f0f0f0f ffffdf85`2de1f158 00000000`00000100 00000000`00000000 : nt!NtOpenProcess+0x23
ffff9606`fad5ba60 fffff807`800730c0 : fffff807`84983d9c fffff807`8498dd08 00000000`00002d10 00000000`00000000 : nt!KiSystemServiceCopyEnd+0x25 (TrapFrame @ ffff9606`fad5ba60)
ffff9606`fad5bbf8 fffff807`84983d9c : fffff807`8498dd08 00000000`00002d10 00000000`00000000 fffff807`7ffc0dd9 : nt!KiServiceLinkage
ffff9606`fad5bc00 fffff807`8498dd24 : 00000000`00000000 00000000`00000000 ffffdf85`2eab4080 ffffdf85`24e506c0 : xxxsysdrv+0x3d9c
ffff9606`fad5bc80 fffff807`7ffc031a : ffffdf85`24e65a70 fffff807`00002000 fffff807`00000000 ffffdf85`00000000 : xxxsysdrv+0xdd24
ffff9606`fad5bcb0 fffff807`7ff93645 : ffffdf85`24e92680 ffffdf85`24e7e040 ffffdf85`24e92680 00000000`00000000 : nt!ExpWorkerThread+0x16a
ffff9606`fad5bd50 fffff807`8007682c : ffff8480`9f180180 ffffdf85`24e92680 fffff807`7ff935f0 00000000`00000000 : nt!PspSystemThreadStartup+0x55
ffff9606`fad5bda0 00000000`00000000 : ffff9606`fad5c000 ffff9606`fad56000 00000000`00000000 00000000`00000000 : nt!KiStartSystemThread+0x1c

这个work在响应的时候也在等待一个ALPC对象，看来这个ALPC对象一直没有返回，我们看一下这个ALPC对象是哪个进程响应的如下：

0: kd> !process ffffdf852eab4080 0
PROCESS ffffdf852eab4080SessionId: 0  Cid: 2d10    Peb: 88097e000  ParentCid: 0310DirBase: 13d836000  ObjectTable: ffffc5074656cd40  HandleCount: 1502.Image: TMBMSRV.exe

从这里我们可以发现ffffdf852eab4080这个进程就是我们IRP发起WorkItem的进程也就是说形成死锁条件：

IRP线程发起Work，然后等待Work完成。
Work线程发送ALPC请求，等待ALPC。
ALPC的完成实在IRP线程，这个线程一直无法响应，导致死锁。

我们看一下Work线程，理论上来说，Work线程不应该需要等待其他事情才对，如下：

ffff9606`fad5b0d0 fffff807`8454b1bb : ffffdf85`263837e8 ffff9606`fad5b3c0 00000000`00000039 ffffc507`47185c70 : tmactmon+0xc7a6
ffff9606`fad5b100 fffff807`8454a64e : ffff9606`fad5b420 ffff9606`fad5b420 ffffdf85`2635ebb0 ffffdf85`00000000 : tmevtmgr!TMEvtCommunicateRoutine+0x2383
ffff9606`fad5b130 fffff807`8044df8a : ffffc507`3e7e6f10 ffff9606`00000000 00000000`000000ac 00000000`00000000 : tmevtmgr!TMEvtCommunicateRoutine+0x1816
ffff9606`fad5b200 fffff807`8047f34b : ffffdf85`24e9cf00 ffff9606`fad5b3a0 00000000`001fffff 00000000`00000240 : nt!ObpCallPreOperationCallbacks+0xfa
ffff9606`fad5b280 fffff807`80527a14 : ffff9606`fad5b830 ffffdf85`2eab4080 00000000`000000ff 00000000`00000000 : nt!ObpCreateHandle+0xa7b
ffff9606`fad5b4c0 fffff807`80527e29 : ffff9606`fad5bae0 00000000`00000000 00000000`00000001 00000000`001fffff : nt!ObOpenObjectByPointer+0x184
ffff9606`fad5b740 fffff807`80526dc3 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!PsOpenProcess+0x289
ffff9606`fad5ba20 fffff807`80080605 : 0f0f0f0f`0f0f0f0f ffffdf85`2de1f158 00000000`00000100 00000000`00000000 : nt!NtOpenProcess+0x23

看起来像是tmevtmgr这个驱动注册了一个OpenProcess打开进程的回调，然后再回调中上报或者做其他处理，将信息发送给TMBMSRV.exe进程处理，结果发现TMBMSRV.exe已经无法响应了，原因是因为TMBMSRV.exe刚好就是Work的发起者。

其实tmevtmgr这个驱动的处理是有一定问题的，因为一般来说，OpenProcess打开进程的回调的处理，对于KernelHandle类的句柄，就不应该做相关操作(因为是系统层面发起的操作)，显然这个驱动并没有做相关处理，我们看一下这个驱动是哪个厂商的：

0: kd> !lmi tmevtmgr
Loaded Module Info: [tmevtmgr] Module: tmevtmgrBase Address: fffff80784540000Image Name: tmevtmgr.sysMachine Type: 34404 (X64)Time Stamp: 5bb47afb Wed Oct  3 16:16:59 2018Size: 18000CheckSum: 276ce
Characteristics: 22
Debug Data Dirs: Type  Size     VA  PointerCODEVIEW    57,  ebe0,    dfe0 RSDS - GUID: {EC060FFF-E831-4DA5-84BA-20C7D628E998}Age: 1, Pdb: d:\aegis_2.976\src\sys\output\fre_wlh_amd64\amd64\tmevtmgr.pdbImage Type: MEMORY   - Image read successfully from loaded memory.Symbol Type: EXPORT   - PDB not foundLoad Report: export symbolsThe following is the available information on tmevtmgr.sys:Product name   AEGIS
Company name    Trend Micro Inc.
File description    TrendMicro Event Management Module
Internal name   TmEvtMgr.sys
Original filename   TmEvtMgr.sys

竟然是Trend Micro，这么大的厂商开发的驱动竟然回出现这种问题。

3. 验证

我们找到了xxxsysdrv的相关代码和作者，通过沟通得知，原来这个驱动需要再Minifilter中做一些比较复杂的事情，我们知道Windows的内核栈是比较小的，不能进行过于深入的栈调用和函数栈不能使用过大，再Minifilter中，文件IO操作导致的内核栈消耗比较大，因此导致内核栈的溢出。

那么在这个驱动中，对于这种情况的处理是在这个复杂操作中使用新的Work去完成操作，并等待Work的完成，有问题吗？看起来似乎比较合理，但是在这里却遇到了问题。

尝试在xxxsysdrv驱动中将TMBMSRV.exe放行掉，结果死锁问题就消失了。

4. 总结

在这里我们可以发现在驱动开发中比较容易犯的错误，而且也比较容易引起问题的操作：

对系统本身的操作进行处理(本例中，对于WorkItem线程中的操作进行处理，并等待)，这个是比较危险的操作，因为系统线程的等待回对系统的正常运行带来比较大的影响。
在过滤驱动中进行等待(在本例中等待第三方的WorkItem完成，结果WorkItem无法完成导致卡死)。不过对于这种情况，似乎WorkItem卡死的锅并不是过滤驱动等待导致的，但是谁让产生了问题了呢！

因此，在驱动中有如果等待通知(或者完成)的情况的话就需要引起足够的注意，虽然我们可以保证正常情况下不会出现死等的情况，但是如果出现过滤驱动的情况呢？而且过滤驱动也使用了与之类似方法呢？

而且，对于系统线程的处理也要特别小心，例如WorkItem这种系统线程，因为这些线程的异常就会导致整个系统出现问题。