https://www.sysnative.com/forums/threads/pnp-timeouts-0x9f.9153/m.
Dakujem! Toto viedlo na podozrenie na deadlock, kedze mam dva thready s lockmi, kde obidva cakaju KeWaitForSingleObject - neviem parametre volani, takze je to iba tip.
0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks..
Resource @ nt!IopDeviceTreeLock (0xfffff80706844a20) Shared 1 owning threads
Threads: ffffc4872f714040-01<*>
KD: Scanning for held locks.
Resource @ nt!PiEngineLock (0xfffff80706844b80) Exclusively owned
Contention Count = 32
NumberOfExclusiveWaiters = 2
Threads: ffffc4872f714040-01<*>
Threads Waiting On Exclusive Access:
ffffc4872fdf6040 ffffc4872b97f080
KD: Scanning for held locks...........................................................................................
Resource @ 0xffffc48722bef290 Exclusively owned
Contention Count = 8
Threads: ffffc48721c1a040-01<*>
KD: Scanning for held locks...
15706 total locks, 3 locks currently held
Hmm, takze deterministicky na jednom z 1000? U mna sa to deje pri kazdom restarte, takze mam mozno smolu.
Ano, v podstatě tak. Dělo se to stabilně na jednom stroji z mnoha (vždy tom stejném).
Aha, tak ked to tak mam, tak je to bez velkych sanci.
Ale logickým krokem je pak se podívat (příkaz !thread) na vlákna v IRP worker threads. Nejzajímavější jsou jejich zásobníky volání (pokud máte správně nastaveny ladící symboly, což by ve výchozím stavu měly +- být), protože podle názvů ovladačů a funkcí, v nichž se právě nachází, lze někdy odhanout, co se děje.
Užitečné také může být se přes !thread podívat na vlákno ffffc4872f714040, které drží jeden z důležitých zámků a možná se zaseklo (!thread ffffc4872f714040).
0: kd> !thread ffffc4872f714040
THREAD ffffc4872f714040 Cid 0004.0a4c Teb: 0000000000000000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable
ffffbf84ce0f4580 NotificationEvent
IRP List:
ffffc4872eefaa20: (0006,04c0) Flags: 00000000 Mdl: 00000000
Not impersonating
DeviceMap ffffd7864de47480
Owning Process ffffc4871fcce080 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 10945 Ticks: 19200 (0:00:05:00.000)
Context Switch Count 3883 IdealProcessor: 1 NoStackSwap
UserTime 00:00:00.000
KernelTime 00:00:00.390
Win32 Start Address nt!ExpWorkerThread (0xfffff80705e25870)
Stack Init ffffbf84ce0f4c90 Current ffffbf84ce0f4140
Base ffffbf84ce0f5000 Limit ffffbf84ce0ef000 Call 0000000000000000
Priority 15 BasePriority 12 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP RetAddr : Args to Child : Call Site
ffffbf84`ce0f4180 fffff807`05e65850 : ffff9b00`73d55180 00000000`ffffffff 00000000`00000000 ffffc487`2d3c0158 : nt!KiSwapContext+0x76
ffffbf84`ce0f42c0 fffff807`05e64d7f : 20061fff`00000002 00000000`00000001 ffffbf84`ce0f4480 fffff807`00000000 : nt!KiSwapThread+0x500
ffffbf84`ce0f4370 fffff807`05e64623 : ffffbf84`00000000 fffff807`00000000 00000000`00000000 ffffc487`2f714180 : nt!KiCommitThreadWait+0x14f
ffffbf84`ce0f4410 fffff807`0b7688a1 : ffffbf84`ce0f4580 ffffc487`00000000 fffff807`00000000 00470080`05000000 : nt!KeWaitForSingleObject+0x233
ffffbf84`ce0f4500 fffff807`0b78e1da : ffffc487`2dfa21a0 ffffc487`2dfa2050 00000000`00000000 00000000`00000000 : ndis!ndisWaitForKernelObject+0x21
ffffbf84`ce0f4540 fffff807`0b6bbc66 : ffffc487`2eefaa20 ffffbf84`ce0f45f0 00000000`00000000 ffffc487`2dfa21a0 : ndis!ndisPnPIrpRemoveDevice+0x126
ffffbf84`ce0f45b0 fffff807`05e52f55 : 00000000`00000001 ffffc487`2dfa2050 00000000`00000001 ffffbf84`ce0f4710 : ndis!ndisPnPDispatch+0x30926
ffffbf84`ce0f4620 fffff807`06287650 : 00000000`00000000 ffffc487`2dfa2050 ffffbf84`ce0f4710 fffff807`06333d80 : nt!IofCallDriver+0x55
ffffbf84`ce0f4660 fffff807`06333a89 : ffffc487`2ddbfa70 ffffc487`2ddbfa70 ffffc487`2df20c70 00000000`00000002 : nt!IopSynchronousCall+0xf8
ffffbf84`ce0f46d0 fffff807`05f6c5c4 : ffffd786`5e0244d0 ffffc487`2df20c70 00000000`00000001 00000000`0000000a : nt!IopRemoveDevice+0x105
ffffbf84`ce0f4780 fffff807`06333652 : ffffc487`2df20c70 00000000`00000018 00000000`00000000 fffff807`06844a80 : nt!PnpRemoveLockedDeviceNode+0x1ac
ffffbf84`ce0f47e0 fffff807`06333387 : ffffc487`2df20c70 ffffbf84`ce0f4860 00000000`00000018 00000000`00000000 : nt!PnpDeleteLockedDeviceNode+0x4e
ffffbf84`ce0f4820 fffff807`063369f1 : ffffc487`2ddbfa70 00000000`00000002 ffffc487`2e302510 00000000`00000000 : nt!PnpDeleteLockedDeviceNodes+0xf7
ffffbf84`ce0f48a0 fffff807`06336c84 : 00000000`00000000 ffffbf84`ce0f4920 ffffc487`2ddbfa70 00000000`00000000 : nt!PipRemoveDevicesInRelationList+0x8d
ffffbf84`ce0f48f0 fffff807`06336b29 : ffffc487`2e302510 00000000`00000001 ffffc487`2e302510 00000000`00000000 : nt!PnpDelayedRemoveWorker+0x114
ffffbf84`ce0f4930 fffff807`05f6d788 : 00000000`00000000 00000000`00000001 00000000`00000000 ffffc487`2df20c70 : nt!PnpChainDereferenceComplete+0xfd
ffffbf84`ce0f4960 fffff807`06332276 : 00000000`00000001 ffffbf84`ce0f4a59 ffffd786`53611da0 00000000`00000001 : nt!PnpIsChainDereferenced+0xac
ffffbf84`ce0f49e0 fffff807`06330347 : ffffbf84`ce0f4b20 ffffc487`2df20c00 ffffbf84`ce0f4b00 ffffd786`00000001 : nt!PnpProcessQueryRemoveAndEject+0x28a
ffffbf84`ce0f4ac0 fffff807`06309e9e : ffffd786`5e0244d0 ffffd786`5c0a8180 ffffc487`1fcaec00 00000000`00000000 : nt!PnpProcessTargetDeviceEvent+0xeb
ffffbf84`ce0f4af0 fffff807`05e25975 : ffffc487`2f714040 ffffc487`2f714040 ffffc487`1fcaece0 ffffc487`2f303c00 : nt!PnpDeviceEventWorker+0x2ce
ffffbf84`ce0f4b70 fffff807`05f17e25 : ffffc487`2f714040 00000000`00000080 ffffc487`1fcce080 000f8225`bcbbbdff : nt!ExpWorkerThread+0x105
ffffbf84`ce0f4c10 fffff807`05ffcdd8 : fffff807`03ba9180 ffffc487`2f714040 fffff807`05f17dd0 000001d7`9fa65cf0 : nt!PspSystemThreadStartup+0x55
ffffbf84`ce0f4c60 00000000`00000000 : ffffbf84`ce0f5000 ffffbf84`ce0ef000 00000000`00000000 00000000`00000000 : nt!KiStartSystemThread+0x28
Tu parametre urcite nesedia, takze neviem, na co sa caka. Tipujem x86-64 call convention, kde sa az parametre od 5 predavaju na stacku a tie tu vidim. (!dv neukazuje nic)
Tu sa iba maze device cez IRP, tak som isiel pozriet na IRP:
0: kd> !irp ffffc4872eefaa20
Irp is active with 3 stacks 3 is current (= 0xffffc4872eefab80)
No Mdl: No System Buffer: Thread ffffc4872f714040: Irp stack trace.
cmd flg cl Device File Completion-Context
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
>[IRP_MJ_PNP(1b), IRP_MN_REMOVE_DEVICE - (2)]
0 0 ffffc4872dfa2050 00000000 00000000-00000000
\Driver\vwifimp
Args: 00000000 00000000 00000000 00000000
0: kd> !devstack ffffc4872dfa2050
!DevObj !DrvObj !DevExt ObjectName
> ffffc4872dfa2050 \Driver\vwifimp ffffc4872dfa21a0 NDMP3
ffffc4872ddbfa70 \Driver\vwifibus ffffc4872de32f80 0000006e
!DevNode ffffc4872df20c70 :
DeviceInst is "{5d624f94-8850-40c3-a3fa-a4fd2080baf3}\vwifimp_wfd\5&373d53f1&6&20"
ServiceName is "vwifimp"
0: kd> !devobj ffffc4872dfa2050
Device object (ffffc4872dfa2050) is for:
NDMP3 \Driver\vwifimp DriverObject ffffc4872de04300
Current Irp 00000000 RefCount 0 Type 00000017 Flags 00002050
SecurityDescriptor ffffd7864e2997e0 DevExt ffffc4872dfa21a0 DevObjExt ffffc4872dfa3900
ExtensionFlags (0x00000808) DOE_REMOVE_PROCESSED, DOE_DEFAULT_SD_PRESENT
Characteristics (0x00000100) FILE_DEVICE_SECURE_OPEN
AttachedTo (Lower) ffffc4872ddbfa70 \Driver\vwifibus
Device queue is not busy.
0: kd> !devobj ffffc4872ddbfa70
Device object (ffffc4872ddbfa70) is for:
0000006e \Driver\vwifibus DriverObject ffffc48721a78e40
Current Irp 00000000 RefCount 0 Type 00000022 Flags 00003044
SecurityDescriptor ffffd7864e2997e0 DevExt ffffc4872de32f80 DevObjExt ffffc4872ddbfbe8 DevNode ffffc4872df20c70
ExtensionFlags (0x00000808) DOE_REMOVE_PROCESSED, DOE_DEFAULT_SD_PRESENT
Characteristics (0x00000180) FILE_AUTOGENERATED_DEVICE_NAME, FILE_DEVICE_SECURE_OPEN
AttachedDevice (Upper) ffffc4872dfa2050 \Driver\vwifimp
Device queue is not busy.
0: kd> !devnode ffffc4872df20c70
DevNode 0xffffc4872df20c70 for PDO 0xffffc4872ddbfa70
Parent 0000000000 Sibling 0000000000 Child 0000000000
InstancePath is "{5d624f94-8850-40c3-a3fa-a4fd2080baf3}\vwifimp_wfd\5&373d53f1&6&20"
ServiceName is "vwifimp"
State = DeviceNodeDeletePendingCloses (0x313)
Previous State = DeviceNodeStarted (0x308)
StateHistory[18] = DeviceNodeStarted (0x308)
StateHistory[17] = DeviceNodeAwaitingQueuedDeletion (0x30e)
StateHistory[16] = DeviceNodeStarted (0x308)
StateHistory[15] = DeviceNodeEnumerateCompletion (0x30d)
StateHistory[14] = DeviceNodeEnumeratePending (0x30c)
StateHistory[13] = DeviceNodeStarted (0x308)
StateHistory[12] = DeviceNodeEnumerateCompletion (0x30d)
StateHistory[11] = DeviceNodeEnumeratePending (0x30c)
StateHistory[10] = DeviceNodeStarted (0x308)
StateHistory[09] = DeviceNodeEnumerateCompletion (0x30d)
StateHistory[08] = DeviceNodeEnumeratePending (0x30c)
StateHistory[07] = DeviceNodeStarted (0x308)
StateHistory[06] = DeviceNodeStartPostWork (0x307)
StateHistory[05] = DeviceNodeStartCompletion (0x306)
StateHistory[04] = DeviceNodeStartPending (0x305)
StateHistory[03] = DeviceNodeResourcesAssigned (0x304)
StateHistory[02] = DeviceNodeDriversAdded (0x303)
StateHistory[01] = DeviceNodeInitialized (0x302)
StateHistory[00] = DeviceNodeUninitialized (0x301)
StateHistory[19] = Unknown State (0x0)
Flags (0x6c010128) DNF_REENUMERATE, DNF_IDS_QUERIED,
DNF_NO_RESOURCE_REQUIRED, DNF_DEVICE_GONE,
DNF_NO_LOWER_DEVICE_FILTERS, DNF_NO_LOWER_CLASS_FILTERS,
DNF_NO_UPPER_DEVICE_FILTERS, DNF_NO_UPPER_CLASS_FILTERS
UserFlags (0x00000002) DNUF_DONT_SHOW_IN_UI
CapabilityFlags (0x00000a81) DeviceD1, SilentInstall,
SurpriseRemovalOK, WakeFromD1
Takze device skoncil v "Unknown state", aj ked neviem, preco sa po deletion znova snazil startovat. Je divne, ze devicy nie su busy a aj tak to skoncio takto.
Kazdopadne vdaka za pomoc!