文章目錄
- Windows 開機啟動卡死分析
-
- 1. 分析
- 2. 驗證
- 3. 總結
Windows 開機啟動卡死分析
最近一位童鞋在開發驅動的時候，說Windows加載驅動之後，開機的時候就出現了卡死，一直無法開機，畫面如下：
卡在這裡一直沒有響應；該童鞋對于這種問題沒有排除經驗，并且分析了他自己寫的驅動，沒發現問題，隻能求助我。本文就是對着這個卡死問題的一篇分析。
1. 分析
搭建虛拟機環境，直接進行雙機調試，發現開機的時候，卡主的堆棧如下：
# ChildEBP RetAddr Args to Child
00 8079e928 83e8710b 00000001 83e870dd 00000000 nt!RtlpBreakWithStatusInstruction
01 8079e930 83e870dd 00000000 00000000 00000b14 nt!KdCheckForDebugBreak+0x22
02 8079e960 83e86f6b 83e83529 3e2cb063 00000000 nt!KeUpdateRunTime+0x164
03 8079e9b8 83e8bc17 86511002 86511002 000000d1 nt!KeUpdateSystemTime+0x613
04 8079e9b8 83e83529 86511002 86511002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
05 8079ea5c 83e8d289 8079e058 00000000 00000000 nt!KeSetEvent+0x64
06 8079eaac 83ebd746 0009ddc0 8079ead8 00000000 nt!IopCompleteRequest+0x23b
07 8079eafc 83e344bd 00000000 00000000 00000000 nt!KiDeliverApc+0x111
08 8079eb10 84053def 00000000 00000000 8fd404d0 nt!KiCheckForKernelApcDelivery+0x24
09 8079eb58 84053e3a 8719ac48 8079ebe4 00000000 nt!MiMapViewOfSection+0x2d3
0a 8079eb88 84054599 8fd404d0 8719ac48 8079ebe4 nt!MmMapViewOfSection+0x2a
0b 8079ec04 83e4a1ea 00000058 ffffffff 0020f680 nt!NtMapViewOfSection+0x204
0c 8079ec04 779e70b4 00000058 ffffffff 0020f680 nt!KiFastCallEntry+0x12a
0d 0020f608 779e5c34 77a3fa19 00000058 ffffffff ntdll!KiFastSystemCallRet
0e 0020f60c 77a3fa19 00000058 ffffffff 0020f680 ntdll!NtMapViewOfSection+0xc
0f 0020f6a0 47a868cf 00000055 0020f6c4 00000000 ntdll!LdrVerifyImageMatchesChecksumEx+0x93
10 0020f768 47a8850d 002afc30 0000001c 47a908e8 smss!SmpInitializeKnownDllsInternal+0x290
11 0020f780 47a8a3e7 00000000 00000000 00000001 smss!SmpInitializeKnownDlls+0x14
12 0020f9f0 47a8a607 00000038 00000000 779b49a5 smss!SmpLoadDataFromRegistry+0x547
13 0020fb60 47a8c290 4789c464 00000000 00000000 smss!SmpInit+0x1e4
14 0020fc00 47a8e946 00000000 002a1ad0 002a1ad8 smss!wmain+0x1f5
15 0020fc44 779a5e7a 002a1b24 7787b16a 00000000 smss!NtProcessStartupW_AfterSecurityCookieInitialized+0x21f
16 0020fc84 77a037c8 47a8e960 7ffda000 00000000 ntdll!__RtlUserThreadStart+0x28
17 0020fc9c 00000000 47a8e960 7ffda000 00000000 ntdll!_RtlUserThreadStart+0x1b
看到是在smss程序啟動的時候，出現了問題，但是這個問題很奇怪，仿佛是
nt!KeSetEvent
這個函數陷入了死循環，我們看下這個函數的實作，發現如下邏輯：
确實這裡是一個lock标記判斷的循環，猜測是這個循環在某種異常情況下退不出去了。我們先不糾結這個循環的邏輯，首先正常情況下
nt!KeSetEvent
這個肯定是沒有問題的，這裡出現問題，首先是懷疑參數是否正确，值得慶幸的是，這個環境是X86的，可以直接看到參數資訊：
kd> dt -r1 nt!_KEVENT 8079e058
+0x000 Header : _DISPATCHER_HEADER
+0x000 Type : 0xcd ''
+0x001 TimerControlFlags : 0xbc ''
+0x001 Absolute : 0y0
+0x001 Coalescable : 0y0
+0x001 KeepShifting : 0y1
+0x001 EncodedTolerableDelay : 0y10111 (0x17)
+0x001 Abandoned : 0xbc ''
+0x001 Signalling : 0xbc ''
+0x002 ThreadControlFlags : 0xec ''
+0x002 CpuThrottled : 0y0
+0x002 CycleProfiling : 0y0
+0x002 CounterProfiling : 0y1
+0x002 Reserved : 0y11101 (0x1d)
+0x002 Hand : 0xec ''
+0x002 Size : 0xec ''
+0x003 TimerMiscFlags : 0x83 ''
+0x003 Index : 0y1
+0x003 Processor : 0y00001 (0x1)
+0x003 Inserted : 0y0
+0x003 Expired : 0y1
+0x003 DebugActive : 0x83 ''
+0x003 ActiveDR7 : 0y1
+0x003 Instrumented : 0y1
+0x003 Reserved2 : 0y0000
+0x003 UmsScheduled : 0y0
+0x003 UmsPrimary : 0y1
+0x003 DpcActive : 0x83 ''
+0x000 Lock : 0n-2081637171
+0x004 SignalState : 0n1001974979
+0x008 WaitListHead : _LIST_ENTRY [ 0xfffffffe - 0x83ecf9be ]
對于上面這個結構，我們可以很明确的得出一個結論，這個結構體是錯誤的（很多資料段很奇怪）。那麼這個結構是哪裡來的呢，繼續從上面堆棧入手：
kd> kb
# ChildEBP RetAddr Args to Child
00 8079e928 83e8710b 00000001 83e870dd 00000000 nt!RtlpBreakWithStatusInstruction
01 8079e930 83e870dd 00000000 00000000 00000b14 nt!KdCheckForDebugBreak+0x22
02 8079e960 83e86f6b 83e83529 3e2cb063 00000000 nt!KeUpdateRunTime+0x164
03 8079e9b8 83e8bc17 86511002 86511002 000000d1 nt!KeUpdateSystemTime+0x613
04 8079e9b8 83e83529 86511002 86511002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
05 8079ea5c 83e8d289 8079e058 00000000 00000000 nt!KeSetEvent+0x64
06 8079eaac 83ebd746 0009ddc0 8079ead8 00000000 nt!IopCompleteRequest+0x23b
07 8079eafc 83e344bd 00000000 00000000 00000000 nt!KiDeliverApc+0x111
08 8079eb10 84053def 00000000 00000000 8fd404d0 nt!KiCheckForKernelApcDelivery+0x24
09 8079eb58 84053e3a 8719ac48 8079ebe4 00000000 nt!MiMapViewOfSection+0x2d3
0a 8079eb88 84054599 8fd404d0 8719ac48 8079ebe4 nt!MmMapViewOfSection+0x2a
0b 8079ec04 83e4a1ea 00000058 ffffffff 0020f680 nt!NtMapViewOfSection+0x204
0c 8079ec04 779e70b4 00000058 ffffffff 0020f680 nt!KiFastCallEntry+0x12a
這裡是在分發APC，并且分發到了
IopCompleteRequest
,這個是用來完成IRP使用的也就是說我們的EVENT應該是來自IRP的，看下線程的IRP結構：
kd> dt nt!_IRP 86807740
+0x000 Type : 0n6
+0x002 Size : 0x94
+0x004 MdlAddress : (null)
+0x008 Flags : 0x60070
+0x00c AssociatedIrp : <unnamed-tag>
+0x010 ThreadListEntry : _LIST_ENTRY [ 0x8709dd90 - 0x8696dca8 ]
+0x018 IoStatus : _IO_STATUS_BLOCK
+0x020 RequestorMode : 0 ''
+0x021 PendingReturned : 0 ''
+0x022 StackCount : 1 ''
+0x023 CurrentLocation : 3 ''
+0x024 Cancel : 0 ''
+0x025 CancelIrql : 0 ''
+0x026 ApcEnvironment : 0 ''
+0x027 AllocationFlags : 0x4 ''
+0x028 UserIosb : 0x8079e050 _IO_STATUS_BLOCK
+0x02c UserEvent : 0x8079e058 _KEVENT //nt!KeSetEvent+0x64 的事件
+0x030 Overlay : <unnamed-tag>
+0x038 CancelRoutine : (null)
+0x03c UserBuffer : 0x8079e078 Void
+0x040 Tail : <unnamed-tag>
這裡确實找到了這個IRP，那麼确定了IRP之後，我們看下IRP的狀态資訊：
kd> !irp 86807740
Irp is active with 1 stacks 3 is current (= 00000000)
No Mdl: System buffer=8687f040: Thread 871993a0: Irp is completed.
cmd flg cl Device File Completion-Context
[IRP_MJ_DEVICE_CONTROL(e), N/A(0)]
0 2 867af6b0 00000000 00000000-00000000
\Driver\mountmgr
Args: 00000000 00000000 0xd063424300000000 c000003b
這個IRP是
IRP_MJ_DEVICE_CONTROL
, 并且這個IRP屬于已經完成了，那麼為什麼會出問題呢？我們看下這個IRP完成的APC是在哪裡調用的呢？
繼續從上面堆棧入手：
kd> kb
# ChildEBP RetAddr Args to Child
00 8079e928 83e8710b 00000001 83e870dd 00000000 nt!RtlpBreakWithStatusInstruction
01 8079e930 83e870dd 00000000 00000000 00000b14 nt!KdCheckForDebugBreak+0x22
02 8079e960 83e86f6b 83e83529 3e2cb063 00000000 nt!KeUpdateRunTime+0x164
03 8079e9b8 83e8bc17 86511002 86511002 000000d1 nt!KeUpdateSystemTime+0x613
04 8079e9b8 83e83529 86511002 86511002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
05 8079ea5c 83e8d289 8079e058 00000000 00000000 nt!KeSetEvent+0x64
06 8079eaac 83ebd746 0009ddc0 8079ead8 00000000 nt!IopCompleteRequest+0x23b
07 8079eafc 83e344bd 00000000 00000000 00000000 nt!KiDeliverApc+0x111
08 8079eb10 84053def 00000000 00000000 8fd404d0 nt!KiCheckForKernelApcDelivery+0x24
09 8079eb58 84053e3a 8719ac48 8079ebe4 00000000 nt!MiMapViewOfSection+0x2d3
0a 8079eb88 84054599 8fd404d0 8719ac48 8079ebe4 nt!MmMapViewOfSection+0x2a
0b 8079ec04 83e4a1ea 00000058 ffffffff 0020f680 nt!NtMapViewOfSection+0x204
0c 8079ec04 779e70b4 00000058 ffffffff 0020f680 nt!KiFastCallEntry+0x12a
這個堆棧就比較奇怪了，因為從
nt!MiMapViewOfSection
這裡完成IRP明顯不是很正确，因為這個地方并不是IRP發起的地方，這個函數是加載鏡像用的。
那麼這裡得出一個猜測，是否是從
nt!MiMapViewOfSection
中間調用了一些列操作，這個時候有些操作産生了IRP，但是無法響應APC例程了，導緻APC例程延遲到這個地方響應。
nt!MiMapViewOfSection
從這個函數來看，最可能執行的操作就是可執行檔案加載的回調函數執行了。問一下那個童鞋，是否在自己的驅動中調用了
PsSetLoadImageNotifyRoutine
函數呢？他說，在驅動中有使用過，那麼基本猜測就是由于
PsSetLoadImageNotifyRoutine
設定的回調函數中産生了新的IRP，因為
PsSetLoadImageNotifyRoutine
這個注冊的回調函數在調用的時候會關閉APC的，MSDN上面如下描述：
When the main executable image for a newly created process is loaded, the load-image notify routine runs in the context of the new process. The operating system calls the driver’s load-image notify routine at PASSIVE_LEVEL inside a critical region with normal kernel APCs always disabled and sometimes with both kernel and special APCs disabled.
2. 驗證
下面我們來驗證分析一下是否是由于這個回調函數導緻的問題，我們調試看到如下調用棧：
kd> kb
# ChildEBP RetAddr Args to Child
00 80796004 89151fad 00000000 86c36820 86c36820 nt!IopfCompleteRequest
01 80796020 83e3d593 86c36820 86c50c80 00000200 volmgr!VmDeviceControl+0x9f3
02 80796038 83ffd942 000000c8 901f7550 870a2720 nt!IofCallDriver+0x63
03 80796898 84049cb4 86c36820 901f7550 bb5f2495 nt!IoVolumeDeviceToDosName+0x7e
04 807968e8 84002c5c 870a2720 00000001 909585b0 nt!IopQueryNameInternal+0xb2
05 80796918 8f9649a0 870a2720 8079695c 00000000 nt!IoQueryFileDosDeviceName+0x2e
06 80796934 8f968897 901e6460 8079695c 00000000 xxxxx
07 807969f4 8f96835c 871da938 000000fc 8718f9b8 xxxxx
08 80796a0c 8407539c 871da938 000000fc 80796a5c xxxxx
09 80796a34 8405d27f 871da938 000000fc 83f48b88 nt!PsCallImageNotifyRoutines+0x62
0a 80796ae8 8404dd4a 8720e008 8718fd40 80796be4 nt!MiMapViewOfImageSection+0x670
0b 80796b58 8404de3a 8718fd40 80796be4 00000000 nt!MiMapViewOfSection+0x22e
0c 80796b88 8404e599 901a04f0 8718fd40 80796be4 nt!MmMapViewOfSection+0x2a
0d 80796c04 83e441ea 00000058 ffffffff 002df7c8 nt!NtMapViewOfSection+0x204
0e 80796c04 77d570b4 00000058 ffffffff 002df7c8 nt!KiFastCallEntry+0x12a
0f 002df750 77d55c34 77dafa19 00000058 ffffffff ntdll!KiFastSystemCallRet
10 002df754 77dafa19 00000058 ffffffff 002df7c8 ntdll!NtMapViewOfSection+0xc
11 002df7e8 47a468cf 00000055 002df80c 00000000 ntdll!LdrVerifyImageMatchesChecksumEx+0x93
12 002df8b0 47a4850d 0045fc30 0000001c 47a508e8 smss!SmpInitializeKnownDllsInternal+0x290
13 002df8c8 47a4a3e7 00000000 00000000 00000001 smss!SmpInitializeKnownDlls+0x14
14 002dfb38 47a4a607 00000038 00000000 77d249a5 smss!SmpLoadDataFromRegistry+0x547
15 002dfca8 47a4c290 4788bccd 00000000 00000000 smss!SmpInit+0x1e4
16 002dfd48 47a4e946 00000000 00451ad0 00451ad8 smss!wmain+0x1f5
17 002dfd8c 77d15e7a 00451b24 77f3cd94 00000000 smss!NtProcessStartupW_AfterSecurityCookieInitialized+0x21f
18 002dfdcc 77d737c8 47a4e960 7ffda000 00000000 ntdll!__RtlUserThreadStart+0x28
19 002dfde4 00000000 47a4e960 7ffda000 00000000 ntdll!_RtlUserThreadStart+0x1b
在
PsCallImageNotifyRoutines
回調函數中，調用了
IoQueryFileDosDeviceName
産生IRP，并且我們看這個線程的APC狀态可以發現：
kd> dt nt!_KTHREAD 8718f9b8 SpecialApcDisable
+0x086 SpecialApcDisable : 0n-1
Special APC被禁用了，
IoCompleteRequest
的完成就依賴這個APC, 而在
IoVolumeDeviceToDosName
有如下邏輯
NTSTATUS
IoVolumeDeviceToDosName(
IN PVOID VolumeDeviceObject,
OUT PUNICODE_STRING DosName
)
{
//...
KEVENT event;
//...
KeInitializeEvent(&event, NotificationEvent, FALSE);
irp = IoBuildDeviceIoControlRequest(IOCTL_MOUNTDEV_QUERY_DEVICE_NAME,
volumeDeviceObject, NULL, 0, name, 512,
FALSE, &event, &ioStatus);
//...
}
這裡
KeInitializeEvent
的是一個臨時變量，當函數傳回的時候，這個變量就無效了，而我們APC的響應在這個函數傳回之後了，導緻這個變量出錯，系統卡死。
3. 總結
在
PsSetLoadImageNotifyRoutine
這個回調函數中，不能做複雜的操作，不能發起IRP請求，否則會導緻IRP完成的時候出現異常。