在调试里看 NV 驱动栈溢出导致的连环死锁原创
最近我使用的一台PC随机出现应用程序卡死。卡死的程序可能是VirtualBox虚拟机，可能是资源管理器，也可能是其它软件。有时是一个程序卡死，有时是几个程序卡死，甚至是卡死一大片，整个系统不能动弹，只好触发蓝屏，或者强按4秒，关机重启。
三次挂死
现在回想起来，第一次发生这个问题时，是在写一篇文章，正在收尾完工的时候，整个系统突然不能反应，屏幕全黑，但是老雷没有放弃，插了个USB键盘上去，过了一会，键盘居然有反应了（数字键盘锁定灯可以亮或者暗），于是老雷按下Ctrl + ScrollLock，触发蓝屏，虽然屏幕已经死了，没有显示，但是根据多年的经验，老雷感觉到了蓝屏是成功的，仿佛看到了那缕蓝光冲破黑暗，闪现出来…重启之后，真的发现有dump保存下来，说明老雷的感觉是对的。
第二次发生这个问题是在北京讲课，讲着讲着老雷兴起，想做个即兴的演示给大家看，没想到在搜索要启动的程序时整个系统卡死，突然的事故让老雷有点措手不及，赶紧解释了一下，然后趁课间休息的时间重启系统。
第三次发生是今天，一方面考虑到周五要做的公开课，另一方面考虑到，已经忍了两次，第三次不能忍了，是可忍孰不可忍:-)
这一次挂死的是WinDBG，老雷唤起它是要做内核调试的，目标机冻结，熟悉的int 3出现，一切顺利，但是WinDBG的命令行始终处于BUSY状态。
通常这样的等待是因为WinDBG在找符号，老雷用这个间隙倒茶。
但这一次，倒好茶还是BUSY，老雷意识到是“小鬼”出现了。
偷摸发信被卡牢
再启动一个WinDBG，附加到已经挂死的WinDBG上，~* k，先是看到调试引擎线程卡在一个关键区上：
1 Id: e24.2fb8 Suspend: 1 Teb: 00000063`3def0000 Unfrozen
# Child-SP RetAddr Call Site
00 00000063`3e2ff278 00007fff`3f43be9b ntdll!NtWaitForAlertByThreadId+0x14
01 00000063`3e2ff280 00007fff`3f43bd01 ntdll!RtlpWaitOnAddressWithTimeout+0x43
02 00000063`3e2ff2b0 00007fff`3f414571 ntdll!RtlpWaitOnCriticalSection+0x1a1
03 00000063`3e2ff360 00007fff`3f414490 ntdll!RtlpEnterCriticalSectionContended+0xd1
04 00000063`3e2ff390 00007fff`28b92d69 ntdll!RtlEnterCriticalSection+0x40
05 00000063`3e2ff3c0 00007fff`28b97ade sqmapi!AcquireSessionFromHandle+0x21
*** ERROR: Symbol file could not be found. Defaulted to export symbols for C:\wd10x64\dbgeng.dll -
06 00000063`3e2ff3f0 00007fff`03849482 sqmapi!SqmAddToStreamString+0x82
07 00000063`3e2ff440 00007fff`038fcbf0 dbgeng!Ordinal327+0x23ce2
08 00000063`3e2ff490 00007fff`038304bb dbgeng!Ordinal327+0xd7450
09 00000063`3e2ff520 00007fff`038307a3 dbgeng!Ordinal327+0xad1b
0a 00000063`3e2ffa10 00007ff6`57094948 dbgeng!Ordinal327+0xb003
0b 00000063`3e2ffa70 00007ff6`57093b1b windbg+0x34948
0c 00000063`3e2ffab0 00007ff6`57095419 windbg+0x33b1b
0d 00000063`3e2ffae0 00007ff6`5707c0c4 windbg+0x35419
0e 00000063`3e2ffb10 00007fff`3eb52774 windbg+0x1c0c4
0f 00000063`3e2ffba0 00007fff`3f470d51 KERNEL32!BaseThreadInitThunk+0x14
10 00000063`3e2ffbd0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
观察这个管件区：
0:010> !locks
CritSec sqmapi!WPP_REGISTRATION_GUIDS+2298 at 00007fff28bc97d0
WaiterWoken No
LockCount 1
RecursionCount 1
OwningThread 3520
EntryCount 0
ContentionCount 1
*** Locked
Scanned 31 critical sections
看来这个关键区是被3520线程捷足先登了，切到这个线程，观察：
2 Id: e24.3520 Suspend: 1 Teb: 00000063`3def2000 Unfrozen
# Child-SP RetAddr Call Site
00 00000063`3e37e538 00007fff`3cf32bf2 ntdll!NtAlpcSendWaitReceivePort+0x14
01 00000063`3e37e540 00007fff`3cfc9b61 RPCRT4!LRPC_BASE_CCALL::DoSendReceive+0x112
02 00000063`3e37e5f0 00007fff`3cfc85bd RPCRT4!NdrpClientCall3+0xa61
03 00000063`3e37ea30 00007fff`2d081090 RPCRT4!NdrClientCall3+0xed
04 00000063`3e37edc0 00007fff`28b9b829 SensApi!IsNetworkAlive+0x80
05 00000063`3e37ee20 00007fff`28ba965e sqmapi!IsNetworkAvailable+0xc9
06 00000063`3e37ee50 00007fff`28b983b8 sqmapi!CSqmHttpUploadManager::AddFilesToUploadQueue+0x7a
07 00000063`3e37f360 00007fff`038498e7 sqmapi!SqmStartUpload+0x1e0
08 00000063`3e37f3c0 00007fff`03849a5b dbgeng!Ordinal327+0x24147
09 00000063`3e37f830 00007fff`3eb52774 dbgeng!Ordinal327+0x242bb
0a 00000063`3e37f860 00007fff`3f470d51 KERNEL32!BaseThreadInitThunk+0x14
0b 00000063`3e37f890 00000000`00000000 ntdll!RtlUserThreadStart+0x21
从#7看，sqmapi!SqmStartUpload，是著名的遥感机制（Telemetry）试图往家里发数据（各位看官，可有读过老雷的“在调试器里看Windows 7发信回家”）。
从IsNetworkAlive看，是在发信之前判断是否有网络。但这个看似简单的问题其实不是那么容易，于是利用RPC发起远程调用。
我们暂不评论偷摸发信是否合理，还是继续追踪为啥判断是否联网这点小事就能把骁勇的WinDBG卡死？
寻找RPC的服务端
又是RPC，仍使用上次的方法，使用本地内核调试找到3520线程，可以看到它真的在等待RPC回应。
THREAD ffffcb008241c080 Cid 0e24.3520 Teb: 000000633def2000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
ffffcb008241c6c8 Semaphore Limit 0x1
Waiting for reply to ALPC Message ffff8a8281d7b650 : queued at port ffffcb007146c6e0 : owned by process ffffcb00713c2640
Not impersonating
DeviceMap ffff8a8283d9b630
Owning Process ffffcb0082fa2640 Image: windbg.exe
Attached Process N/A Image: N/A
Wait Start TickCount 3574818 Ticks: 89602 (0:00:23:20.031)
Context Switch Count 7 IdealProcessor: 1
观察服务进程：
lkd> !process ffffcb00713c2640 0
PROCESS ffffcb00713c2640
SessionId: 0 Cid: 07c8 Peb: 93377db000 ParentCid: 033c
DirBase: 11145b000 ObjectTable: ffff8a827e09d340 HandleCount: 199.
Image: svchost.exe
原来是svchost，根据进程ID（7c8，即1992）到服务列表里查找，可以知道它是“系统事件通知服务” System Event Notification Service (SENS)
SENS机制是有文档的，MSDN很详细。
探索SENS服务
接下来观察SENS服务进程的情况，特别注意WinDBG所调用RPC的服务线程（通过!alpc -m消息可以知道）。
结果让人吃惊，和上次微信的例子有点类似，又是连环的RPC，这个服务线程又发起RPC了，在等待回复。
THREAD ffffcb0081b95040 Cid 07c8.1dc0 Teb: 000000933765c000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
ffffcb0081b95688 Semaphore Limit 0x1
Waiting for reply to ALPC Message ffff8a827dcca040 : queued at port ffffcb007f2d0890 : owned by process ffffcb007e967080
Not impersonating
DeviceMap ffff8a826f602090
Owning Process ffffcb00713c2640 Image: svchost.exe
Attached Process N/A Image: N/A
Wait Start TickCount 3658023 Ticks: 456617 (0:01:58:54.640)
Context Switch Count 237 IdealProcessor: 2
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address ntdll!TppWorkerThread (0x00007fff3f4412c0)
Stack Init ffff9e01ddd7fc10 Current ffff9e01ddd7f3c0
Base ffff9e01ddd80000 Limit ffff9e01ddd79000 Call 0000000000000000
Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Kernel stack not resident.
它为啥要发起RPC呢？可以再挂一个调试器在SENS服务上观察。
从#0a看，上面这个线程真的是在处理WinDBG发起的网络是否可用的请求，执行的函数是sens!RPC_IsNetworkAlive。但是这个问题，对于它来说也不能做主，要继续调用RasApi32!RasEnumConnectionsW。这个函数是有文档的：
DWORD RasEnumConnections(
_Inout_ LPRASCONN lprasconn,
_Inout_ LPDWORD lpcb,
_Out_ LPDWORD lpcConnections
);
不过我们不想读，因为从栈上来看，它内部又发起了RPC，与我们在内核态看到的结论是一致的。
RAS服务
从函数名可以看出，SENS服务调用的是RAS服务。有了这个信息可以从服务列表里找RAS服务，也可以继续用我们的内核调试会话找。无论哪种方法，结论都是，SENS服务调用的是进程ID为3488的svchost进程。
再开一个WinDBG（上调试器），以非入侵方式附加到3488进程，~* k观察。立刻发现了特殊情况：第31号线程的栈帧特别多，显示的很长，而且感觉还没有显示完整。
切换到31号线程，k 2000。用了几十秒，才显示完毕，一共有3130（c3a）个栈帧。
根据老雷的经验，这样疯狂的调用，很可能把栈用光了。
观察寄存器现场：
0:031> r
rax=0000000000000001 rbx=00007fff03fb3060 rcx=000000046db83f10
rdx=0000000000000000 rsi=000001fd79f640a0 rdi=000000046db84140
rip=00007fff03fb3103 rsp=000000046db83ee0 rbp=000000046db83fe0
r8=0000000000000180 r9=000000046db84404 r10=0000000000000004
r11=000000046db840c8 r12=0000000000000001 r13=000001fd78a82c30
r14=0000000000000000 r15=0000000000000000
iopl=0 nv up ei pl zr na po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00010244
D3D12!NDXGI::CDevice::SubmitCommandCB+0xa3:
00007fff`03fb3103 e8f07b0200 call D3D12!memset (00007fff`03fdacf8)
显示栈指针附近的内存：
0:031> dd 000000046db83ee0
00000004`6db83ee0 00000000 00000000 00000000 00000000
可以显示，说明栈上有可用内存。
但是从内核态观察这个线程，明明是有异常发生了。
这是怎么回事呢？
听过老雷课的或者认真读过《软件调试》的，或许已经想出了原因。
用户态的栈式可以自动增长的，一般是先保留1MB，提交一点点，提交部分上面放一个保护页，用完了就会碰到保护页，于是再提交。
但是这个过程不是无止境的，在32位时，当栈的保护页已经到了保留的最后一个页时，保护页无处可移，系统这时会发出栈溢出异常，通知应用程序，栈要用完了。
观察31号线程的栈，果然已经没有保护页了（带PAGE_GUARD属性）。
看来真的是栈溢出了。
谁用光了栈
那么是谁用光了栈空间呢？浏览k命令的结果，很容易看出答案，名为nvwgf2umx_cfg的模块似乎陷入了死循环，反复调用数千次：
这个模块是谁家的呢？nv啊！GPU时代的一号公司。
看文件日期，还是很新的文件。
辕门失火
那么RAS服务内部为什么要调用NV的模块呢？浏览31号线程的栈帧，看它为何发起长调用。
发起模块是wuaueng，微软给出的大名叫Windows Update Agent，全称或许为Windows更新自动引擎。
从下面的这些栈帧来看，自动更新引擎是在努力的找活干（FindUpdates），从服务器那边拿到信息后评估在本机的适用性（EvaluateUpdateApplicabilityRules），规则似乎挺复杂的，支持表达式，在评估表达式时，先调用了D3D接口，而后转到了NV的驱动模块。
c1d nvwgf2umx_cfg!OpenAdapter12
c1e nvwgf2umx_cfg!OpenAdapter12
c1f nvwgf2umx_cfg!OpenAdapter12
c20 nvwgf2umx_cfg!NVENCODEAPI_Thunk
c21 nvwgf2umx_cfg!NVENCODEAPI_Thunk
c22 D3D12!NDXGI::CDevice::CreateDriverInstance
c23 D3D12!CDevice::LLOCompleteLayerConstruction
c24 D3D12!NDXGI::CDevice::LLOCompleteLayerConstruction
c25 D3D12!D3D12CreateLayeredDevice
c26 D3D12!D3D12CoreCreateLayeredDevice
c27 D3D12!D3D12CoreCreateDevice
c28 D3D12!D3D12CreateDeviceImpl
c29 D3D12!D3D12CreateDevice
c2a wuaueng!Direct3DEvaluator::GetMaxSupportedD3D12FeatureLevel
c2b wuaueng!Direct3DEvaluator::EvaluateFeatureLevel
c2c wuaueng!CSystemExprEvaluator::EvaluateDirect3D
c2d wuaueng!CSystemExprEvaluator::Evaluate
c2e wuaueng!CBaseEEHandler::Evaluate3
c2f wuaueng!CExprElementTreeNode::Evaluate
c30 wuaueng!CAgentUpdateManager::EvaluateUpdateApplicabilityRules
c31 wuaueng!CAgentUpdateManager::DetectForUpdate
c32 wuaueng!CAgentUpdateManager::EvaluateUpdateSet
c33 wuaueng!CAgentUpdateManager::DetectForUpdates
c34 wuaueng!CAgentProtocolTalker::SyncServerUpdatesInternal
c35 wuaueng!CAgentProtocolTalker::SyncServerUpdates
c36 wuaueng!CAgentUpdateManager::FindUpdates
看来是自动更新逻辑引发了NV模块的疯狂逻辑。两个逻辑可能没有磨合太好。一个说“兄弟你啥版本啊，需要更新不”，“另一个说，更新更新，整天更新个锤子啊”，一言不合，索性把栈用光。哈哈，结果大家都动不了了。
那么自动更新增么和RAS扯到一起的呢？
它们本来真的没有一毛钱关系。只是租房子的时候住到了一起，就为了节约点开销啊。
这样分析下来，可以比较确定的说，随机卡死案件的起因是有人检查网络是否可用（IsNetworkAvailable），RPC调用先是到了SENS服务，又到了RAS服务。在调用时，不想刚好遇到与RAS服务合租的WUAU服务屋里“起火”，更新引擎的表达式平谷逻辑调用NV的驱动模块，后者把栈用完，导致整个进程被挂起，于是RAS和WUAU都动不了了，SENS服务卡住了，调用者也卡住了。
这个结论与曾经分析过的微信挂死颇为类似，结论都与第三方驱动相关。上次是MaxxAudio，这次是大名鼎鼎的NV…
