Нужно подтолкнуть (windbg)

Доброго времени суток.

Изучаю windbg, стоит задача по crashdump'у определить причину зависания драйвера (самого драйвера нет и исходников тоже нет). Какой алгоритм поиска подобных проблем ? Какие команды при этом использовать ?

Заранее спасибо.

 

Открыть крэшдамп, набрать !analyze -v и медитировать

 

Ну, например, самое тупое, что можно сделать: посмотреть какие потоки активны на каждом процессоре (!pcr <n>) и посмотреть их стеки вызовов (!thread <ethread>). Обычно, так можно поймать дедлок на спинлоках. Ещё можно запустить Verifier (в командной строке verifier /flags 0x7b /driver <name> и перезагрузиться), иногда он тоже ловит дедлоки, но не во всех случаях, к сожалению. Если ничего не помогло, тогда тупо получаем список всех потоков в системе (!process 0 6) и анализируем их стеки вызовов, жмём Ctrl-F и ищем имя драйвера (т.е. строку вида "name!"), а там по именам вызываемых функций можно понять примерно, где косяк. Если проблема в I/O-запросах, тогда смотрим список IRPs у потока и анализируем каждый (!irp <irp> 1). Ну и конечно, всё сильно зависит от типа драйвера и его специфики.

Да, и разумеется, всё это следует делать будучи подключённым к сбойной системе (например, запустить драйвер в виртуалке, подключиться к ней WinDbg и отлаживать, если это возможно. Если так сделать нет возможности, тогда нужно вручную сгенерировать дамп падения в момент зависания, открыть его в WinDbg, а далее уже действовать, как описано выше. Как создать файл дампа с клавиатуры в момент зависания описано здесь. И, как правильно заметили выше, прежде всего желательно выполнить первичный анализ дампа (если это именно дамп, а не живая система) командой !analyze -v.

 

!deadlock, !locks

 

Код (Text):

1. KD: Scanning for held locks...........................
2.  
3. Resource @ 0x8df8102c    Shared 1 owning threads
4.      Threads: 8ccbe118-01<*>
5. KD: Scanning for held locks........................................................................................................................................................................................
6. 6723 total locks, 1 locks currently held
7. 0: kd> !thread 8ccbe118
8. THREAD 8ccbe118  Cid 01e8.0224  Teb: 7ffdd000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
9.     91a2b974  NotificationEvent
10. IRP List:
11.     8cf62408: (0006,01d8) Flags: 00060043  Mdl: 8cdf86e0
12. Not impersonating
13. DeviceMap                 90808980
14. Owning Process            8df58030       Image:         wininit.exe
15. Attached Process          N/A            Image:         N/A
16. Wait Start TickCount      39610          Ticks: 6397 (0:00:01:39.953)
17. Context Switch Count      33            
18. UserTime                  00:00:00.000
19. KernelTime                00:00:00.000
20. Win32 Start Address 0x7784d63e
21. Stack Init 91a2bfd0 Current 91a2b708 Base 91a2c000 Limit 91a29000 Call 0
22. Priority 14 BasePriority 13 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
23. ChildEBP RetAddr  Args to Child              
24. 91a2b720 82872b15 8ccbe118 00000000 8292dd20 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
25. 91a2b758 82871403 8ccbe1d8 8ccbe118 91a2b974 nt!KiSwapThread+0x266
26. 91a2b780 8286b2cf 8ccbe118 8ccbe1d8 00000000 nt!KiCommitThreadWait+0x1df
27. 91a2b7fc 8fa264e2 91a2b974 00000000 00000000 nt!KeWaitForSingleObject+0x393
28. 91a2b81c 8fa250e3 91a2ba20 00000000 00000000 Ntfs!NtfsWaitOnIo+0x1c (FPO: [Non-Fpo])
29. 91a2b93c 8fa294e8 91a2ba20 8cf62408 9907e0f8 Ntfs!NtfsNonCachedIo+0x456 (FPO: [Non-Fpo])
30. 91a2ba10 8fa2cbae 91a2ba20 8cf62408 00c8070a Ntfs!NtfsCommonRead+0x1148 (FPO: [Non-Fpo])
31. 91a2bb54 828404bc 8d452020 8cf62408 8cf62408 Ntfs!NtfsFsdRead+0x279 (FPO: [Non-Fpo])
32. 91a2bb6c 83b2220c 8d401d08 8cf62408 00000000 nt!IofCallDriver+0x63
33. 91a2bb90 83b223cb 91a2bbb0 8d401d08 00000000 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x2aa (FPO: [Non-Fpo])
34. 91a2bbc8 828404bc 8d401d08 8cf62408 8cf62408 fltmgr!FltpDispatch+0xc5 (FPO: [Non-Fpo])
35. 91a2bbe0 828a9000 8cdf8698 8ccbe118 8cdf8668 nt!IofCallDriver+0x63
36. 91a2bbfc 828affad 8df81940 8ccbe118 8cdf86a0 nt!IoPageRead+0x1f5
37. 91a2bc94 8288c428 8df58220 75957259 8cdf8669 nt!MiIssueHardFault+0x28c
38. 91a2bd1c 8284a5f8 00000008 75957259 00000001 nt!MmAccessFault+0x2c3a
39. 91a2bd1c 75957259 00000008 75957259 00000001 nt!KiTrap0E+0xdc (FPO: [0,0] TrapFrame @ 91a2bd34)
40. WARNING: Frame IP not in any known module. Following frames may be wrong.
41. 004bf4c0 00000000 00000000 00000000 00000000 0x75957259
42.  
43. 0: kd> !irp 8cf62408
44. Irp is active with 9 stacks 4 is current (= 0x8cf624e4)
45.  Mdl=8cdf86e0: No System Buffer: Thread 8ccbe118:  Irp stack trace.  
46.      cmd  flg cl Device   File     Completion-Context
47.  [  0, 0]   0  0 00000000 00000000 00000000-00000000    
48.  
49.             Args: 00000000 00000000 00000000 00000000
50.  [  0, 0]   0  0 00000000 00000000 00000000-00000000    
51.  
52.             Args: 00000000 00000000 00000000 00000000
53.  [  0, 0]   0  0 00000000 00000000 00000000-00000000    
54.  
55.             Args: 00000000 00000000 00000000 00000000
56. >[  3,34]  10 e0 8d3ef030 00000000 82fcc24e-00000000 Success Error Cancel
57.            \Driver\Disk partmgr!PmReadWriteCompletion
58.             Args: 00008000 00000000 e7997400 00000000
59.  [  3, 0]  10 e0 8d3efc70 00000000 82ff07a4-8d3f10e8 Success Error Cancel
60.            \Driver\partmgr  volmgr!VmpReadWriteCompletionRoutine
61.             Args: 83750e9f 00000000 e7997400 00000000
62.  [  3, 0]   0 e0 8d3f1030 00000000 8fd4f3e2-8d3f18b8 Success Error Cancel
63.            \Driver\volmgr   fvevol!FvePassThroughCompletion
64.             Args: 00008000 00000000 83750e9a 00000000
65.  [  3, 0]   0 e0 8d3f1800 00000000 8ffa47d0-8cf3aaf8 Success Error Cancel
66.            \Driver\fvevol   volsnap!VspReadCompletionRoutine
67.             Args: 00008000 00000000 e7897400 00000000
68.  [  3, 0]   0 e1 8d3f55a8 00000000 8fa264f9-91a2b970 Success Error Cancel pending
69.            \Driver\volsnap  Ntfs!NtfsMasterIrpSyncCompletionRoutine
70.             Args: 00008000 00000000 e7897400 00000000
71.  [  3, 0]   0  0 8d452020 8df81940 00000000-00000000    
72.            \FileSystem\Ntfs
73.             Args: 00008000 00000000 00012400 00000000
74. 0: kd> !fileobj 8df81940
75.  
76. \Windows\System32\winsta.dll
77.  
78. Device Object: 0x8d3f1030   \Driver\volmgr
79. Vpb: 0x8d3f2240
80. Access: Read SharedRead SharedDelete
81.  
82. Flags:  0x44042
83.     Synchronous IO
84.     Cache Supported
85.     Cleanup Complete
86.     Handle Created
87.  
88. FsContext: 0x9907e0f8   FsContext2: 0x990819c0
89. CurrentByteOffset: 0
90. Cache Data:
91.   Section Object Pointers: 8df81070
92.   Shared Cache Map: 00000000

Система зависает где-то при обработке данного файла на ожидании, а как бы поподробнее узнать причину ?

 

Выполни эти команды: !deadlock, !locks
Думаю было исключения в файловом дрове(судя со стека) и локер не был отпущен.

 

В системе на данный момент в состоянии RUNNING находятся два потока, один из них обрабатывает KeBugCheckEx.
А вот второй:

Код (Text):

1. 0: kd> !thread 8cc3fa70
2. THREAD 8cc3fa70  Cid 0004.0034  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 1
3. IRP List:
4.     8d3f1398: (0006,0094) Flags: 00060070  Mdl: 00000000
5.     8ced25a8: (0006,0094) Flags: 00060070  Mdl: 00000000
6.     8cf0d778: (0006,0094) Flags: 00060070  Mdl: 00000000
7.     8d3f6140: (0006,0094) Flags: 00060070  Mdl: 00000000
8.     8e3f8458: (0006,0094) Flags: 00060070  Mdl: 00000000
9.     8ce9cb80: (0006,0094) Flags: 00060070  Mdl: 00000000
10.     8ce593b8: (0006,0094) Flags: 00060070  Mdl: 00000000
11.     8cee0008: (0006,0094) Flags: 00060070  Mdl: 00000000
12.     8e0d5468: (0006,0094) Flags: 00060070  Mdl: 00000000
13.     8e9b4598: (0006,0094) Flags: 00060070  Mdl: 00000000
14.     8e2ee888: (0006,0094) Flags: 00060070  Mdl: 00000000
15.     8cf5d400: (0006,0094) Flags: 00060040  Mdl: 00000000
16. Not impersonating
17. DeviceMap                 90808980
18. Owning Process            8cc20020       Image:         System
19. Attached Process          N/A            Image:         N/A
20. Wait Start TickCount      39580          Ticks: 6427 (0:00:01:40.421)
21. Context Switch Count      1790            
22. UserTime                  00:00:00.000
23. KernelTime                00:01:40.437
24. Win32 Start Address nt!ExpWorkerThread (0x82871e1e)
25. Stack Init 91b1bfd0 Current 91b1b2f8 Base 91b1c000 Limit 91b19000 Call 0
26. Priority 12 BasePriority 12 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
27. ChildEBP RetAddr  Args to Child              
28. 91b1bbcc 828a6351 8e9cbcb0 00000000 00000000 nt!KeSetEvent+0x64
29. 91b1bc1c 828abfa9 00f5d440 91b1bc48 00000000 nt!IopCompleteRequest+0x23b
30. 91b1bc6c 8282d90e 00000000 00000000 00000000 nt!KiDeliverApc+0x111
31. 91b1bc80 829bb735 af773bd0 af773ad0 8d22c908 nt!KiCheckForKernelApcDelivery+0x24
32. 91b1bcd8 829bad48 af773bd4 00000000 8e0fc390 nt!PnpNotifyTargetDeviceChange+0x146
33. 91b1bd00 82871f2b 8e0fc390 00000000 8cc3fa70 nt!PnpDeviceEventWorker+0x206
34. 91b1bd50 82a1266d 00000001 b032460d 00000000 nt!ExpWorkerThread+0x10d
35. 91b1bd90 828c40d9 82871e1e 00000001 00000000 nt!PspSystemThreadStartup+0x9e
36. 00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19

И судя по всему он крутится внутри KeSetEvent в цикле:

Код (Text):

1. .text:00454CAD loc_454CAD:                       ; CODE XREF: KeSetEvent(x,x,x)+68
2. .text:00454CAD                                         ; KeSetEvent(x,x,x)+71
3. .text:00454CAD                 inc     edi
4. .text:00454CAE                 test    ds:_HvlLongSpinCountMask, edi
5. .text:00454CB4                 jnz     short loc_454CC7
6. .text:00454CB6                 test    byte ptr ds:_HvlEnlightenments, 40h
7. .text:00454CBD                 jz      short loc_454CC7
8. .text:00454CBF                 push    edi
9. .text:00454CC0                 call    _HvlNotifyLongSpinWait@4 ; HvlNotifyLongSpinWait(x)
10. .text:00454CC5                 jmp     short loc_454CC9
11. .text:00454CC7 ; ---------------------------------------------------------------------------
12. .text:00454CC7
13. .text:00454CC7 loc_454CC7:                        ; CODE XREF: KeSetEvent(x,x,x)+4F
14. .text:00454CC7                                         ; KeSetEvent(x,x,x)+58
15. .text:00454CC7                 pause
16. .text:00454CC9
17. .text:00454CC9 loc_454CC9:                       ; CODE XREF: KeSetEvent(x,x,x)+60
18. .text:00454CC9                 mov     eax, [esi]
19. .text:00454CCB                 test    al, al
20. .text:00454CCD                 js      short loc_454CAD

Может быть кто-нибудь знает, что здесь проверяется и куда дальше копать ?
И видимо пока событие не перейдет состоянии Signal, висит лок на файле.