Ndis MINIPORT_HALT fails to get called after calling NdisIMDeInitializeDeviceInstance

Shashank_Ram · November 22, 2016, 11:03pm

Hi, I have an Ndis 6.30 IM driver, with 2 miniports bound to my driver’s protocol edge. I am noticing an issue during driver unload, where the MINIPORT_HALT does not get called by NDIS upon calling “NdisIMDeInitializeDeviceInstance(miniportAdapterHandle)” from within my protocol’s PROTOCOL_UNBIND_ADAPTER_EX handler.

This happens most of the times during unload, and looking at the OID and Send counters, I do not see any pending requests.
When I pass traffic, the driver works as expected. My unbind/unload logic is pretty much like whats in the Windows Mux sample driver code.

Basically, NdisIMDeInitializeDeviceInstance() blocks and never returns. I continue to get OIDs once this happens, and my driver is stuck during unload when this happens.

Here is some debugging info I captured when this happened:

0: kd> !ndiskd.miniports

.reload ndis.sys…
Reload succeeded.

MiniDriver Miniport Name
ffffe00002bd6020 ffffe0000390b1a0 Microsoft ISATAP Adapter #2
ffffe00002bd6020 ffffe0000224f1a0 Microsoft ISATAP Adapter #3
ffffe00001ffaa30 ffffe00001e2a1a0 1 - Miniport
ffffe00001ffaa30 ffffe00001e281a0 2 - Miniport
ffffe00002bd6020 ffffe00002da91a0 Microsoft ISATAP Adapter
ffffe00002ffe920 ffffe000016051a0 WAN Miniport (PPPOE)
ffffe00002ff8ba0 ffffe00002ff91a0 WAN Miniport (L2TP)
ffffe00002ebf260 ffffe00002ff51a0 WAN Miniport (Network Monitor)
ffffe00002fee330 ffffe00002ff31a0 WAN Miniport (PPTP)
ffffe00002f3fba0 ffffe00002fde1a0 Intel(R) 82574L Gigabit Network Connection #2
ffffe00002ebf260 ffffe00002fbc1a0 WAN Miniport (IPv6)
ffffe00002ee3ba0 ffffe00002fba1a0 Microsoft Kernel Debug Network Adapter
ffffe00002ed3680 ffffe00002fb71a0 WAN Miniport (IKEv2)
ffffe00002ecfba0 ffffe00002fa01a0 WAN Miniport (SSTP)
ffffe00002ebf260 ffffe00002f9e1a0 WAN Miniport (IP)

========================================================================

0: kd> !ndiskd.miniport ffffe00001e2a1a0

MINIPORT

1 - Miniport

Ndis handle ffffe00001e2a1a0
Ndis API version v6.30
Adapter context ffffe000030003f0
Miniport driver ffffe00001ffaa30 - TIMMP v3.0
Network interface ffffe0000378da20

Media type 802.3
Device instance ROOT\TIMMP\0000
Device object ffffe00001e2a050 !miniport ffffe00001e2a1a0 -device
MAC address 00-0c-29-f8-34-9c

STATE

Miniport Running
Device PnP STOPPED !miniport ffffe00001e2a1a0 -log
Datapath Normal
Interface Up
Media Connected
Power D0
References 9 !miniport ffffe00001e2a1a0 -ref
Total resets 0
Pending OID None
Flags NOT_BUS_MASTER, INTERMEDIATE_DRIVER,
DEFAULT_PORT_ACTIVATED, NOT_RESOURCES_AVAILABLE,
SUPPORTS_MEDIA_SENSE, DOES_NOT_DO_LOOPBACK,
MEDIA_CONNECTED
PnP flags PM_SUPPORTED, DEVICE_POWER_ENABLED, NO_HALT_ON_SUSPEND,
RECEIVED_START, VERIFYING

BINDINGS

Bind operations are in progress .thread /p ffffe00003727080; kM

Protocol list Driver Open Context
TCPIP ffffe000028c6620 ffffe000023dd610 ffffe00003893330
TCPIP6 ffffe000028c7620 ffffe000023de8a0 ffffe000038d0330
(RASPPPOE) ffffe00002ffe510 Declined with NDIS_STATUS_FAILURE
(NDISUIO) Not running
LLTDIO ffffe00002e2b6b0 ffffe000023e5c10 ffffe000023d9af0
RSPNDR ffffe00002e33490 ffffe000023e6c10 ffffe000038c46a0
(RDMANDK) ffffe00002e6fc10 Declined with NDIS_STATUS_NOT_RECOGNIZED

Filter list Driver Module Context
WFP 802.3 MAC Layer LightWeight Filter-0000
ffffe00002984d70 ffffe00003789470 ffffe000023d4210
QoS Packet Scheduler-0000
ffffe00002e71750 ffffe0000308b010 ffffe000033a1180
WFP Native MAC Layer LightWeight Filter-0000
ffffe00002984ad0 ffffe000023da260 ffffe0000307e010

MORE INFORMATION

!minidriver ffffe00001ffaa30 -handlers !miniport ffffe00001e2a1a0 -offloads
!miniport ffffe00001e2a1a0 -pm !miniport ffffe00001e2a1a0 -protocoloffloads
!oid -miniport ffffe00001e2a1a0 !miniport ffffe00001e2a1a0 -timers
!pendingnbls ffffe00001e2a1a0
!miniport ffffe00001e2a1a0 -wol !miniport ffffe00001e2a1a0 -filterdb
!miniport ffffe00001e2a1a0 -rcvqueues !miniport ffffe00001e2a1a0 -rcvfilter
!miniport ffffe00001e2a1a0 -rss !miniport ffffe00001e2a1a0 -nicswitch
!miniport ffffe00001e2a1a0 -hw !miniport ffffe00001e2a1a0 -ss
!miniport ffffe00001e2a1a0 -ports !miniport ffffe00001e2a1a0 -wmi
0: kd> !oid -miniport ffffe00001e2a1a0

ALL PENDING OIDs

[Showing all OIDs on the stack for miniport ffffe00001e2a1a0]

No pending or queued OIDs were found.
0: kd> !pendingnbls ffffe00001e2a1a0

PHASE 1/3: Found 39 NBL pool(s).
A timeout occurred. The timeout can be increased in the Debugging options page
A timeout occurred. The timeout can be increased in the Debugging options page
A timeout occurred. The timeout can be increased in the Debugging options page
A timeout occurred. The timeout can be increased in the Debugging options page
PHASE 2/3: Found 82 freed NBL(s).

Pending Nbl Currently held by
A timeout occurred. The timeout can be increased in the Debugging options page
A timeout occurred. The timeout can be increased in the Debugging options page
A timeout occurred. The timeout can be increased in the Debugging options page
No pending NBLs were found.

PHASE 3/3: Found 0 pending NBL(s) of 2130 total NBL(s).
Search complete.
0: kd> !oid -miniport ffffe00001e2a1a0

ALL PENDING OIDs

[Showing all OIDs on the stack for miniport ffffe00001e2a1a0]

0: kd> !ndiskd.mopen ffffe00001e2a1a0

OPEN

Ndis handle ffffe00001e2a1a0
Flags [Unrecognized flags 00a02280] OPEN_CLOSING,
OPEN_CALL_MANAGER, NO_BIND_REQUEST, USE_MULTICAST_LIST
References ffffe000 !mopen ffffe00001e2a1a0 -ref
Source Cannot load field ‘m_bindSources’ in ‘class Ndis::BindState’
Datapath state [Unreadable value]
Pause reason [Unreadable value]
Unbind reason [Unreadable value]

Protocol ffffe000030003f0 - [Zero-length string]
Protocol context 00001e06

Miniport ffffe00001e2a1a0 - 1 - Miniport
Miniport context ffffe000023e6c10

RECEIVE PATH

Packet filter [Unrecognized flags 00700800] ALL_MULTICAST, ALL_LOCAL
Frame Type(s) [This protocol has not registered any frame types]
Only showing the first 256 of 7324844 multicast addresses
Multicast address list 08-57-48-83-ec-20 !miniport ffffe00001e2a1a0 -filterdb
39-03-00-04-72-14
00-b9-1a-00-00-00
—> Has a bunch of more MAC entries

===============================================================================================
No pending or queued OIDs were found.
0: kd> !ndiskd.miniports
MiniDriver Miniport Name
ffffe00002bd6020 ffffe0000390b1a0 Microsoft ISATAP Adapter #2
ffffe00002bd6020 ffffe0000224f1a0 Microsoft ISATAP Adapter #3
ffffe00001ffaa30 ffffe00001e2a1a0 1 - Miniport
ffffe00001ffaa30 ffffe00001e281a0 2 - Miniport
ffffe00002bd6020 ffffe00002da91a0 Microsoft ISATAP Adapter
ffffe00002ffe920 ffffe000016051a0 WAN Miniport (PPPOE)
ffffe00002ff8ba0 ffffe00002ff91a0 WAN Miniport (L2TP)
ffffe00002ebf260 ffffe00002ff51a0 WAN Miniport (Network Monitor)
ffffe00002fee330 ffffe00002ff31a0 WAN Miniport (PPTP)
ffffe00002f3fba0 ffffe00002fde1a0 Intel(R) 82574L Gigabit Network Connection #2
ffffe00002ebf260 ffffe00002fbc1a0 WAN Miniport (IPv6)
ffffe00002ee3ba0 ffffe00002fba1a0 Microsoft Kernel Debug Network Adapter
ffffe00002ed3680 ffffe00002fb71a0 WAN Miniport (IKEv2)
ffffe00002ecfba0 ffffe00002fa01a0 WAN Miniport (SSTP)
ffffe00002ebf260 ffffe00002f9e1a0 WAN Miniport (IP)

==================================================================================================

0: kd> !ndiskd.miniport ffffe00001e281a0

MINIPORT

2 - Miniport

Ndis handle ffffe00001e281a0
Ndis API version v6.30
Adapter context ffffe00002dfb3f0
Miniport driver ffffe00001ffaa30 - TIMMP v3.0
Network interface ffffe000037902c0

Media type 802.3
Device instance ROOT\TIMMP\0001
Device object ffffe00001e28050 !miniport ffffe00001e281a0 -device
MAC address 00-0c-29-f8-34-9c

STATE

Miniport Running
Device PnP Started !miniport ffffe00001e281a0 -log
Datapath Normal
Interface Up
Media Connected
Power D0
References 8 !miniport ffffe00001e281a0 -ref
Total resets 0
Pending OID None
Flags NOT_BUS_MASTER, INTERMEDIATE_DRIVER,
DEFAULT_PORT_ACTIVATED, NOT_RESOURCES_AVAILABLE,
SUPPORTS_MEDIA_SENSE, DOES_NOT_DO_LOOPBACK,
MEDIA_CONNECTED
PnP flags PM_SUPPORTED, DEVICE_POWER_ENABLED, NO_HALT_ON_SUSPEND,
RECEIVED_START, VERIFYING

BINDINGS

Protocol list Driver Open Context
TCPIP ffffe000028c6620 ffffe000037fc200 ffffe0000383e330
TCPIP6 ffffe000028c7620 ffffe0000307f500 ffffe000023d6330
(RASPPPOE) ffffe00002ffe510 Declined with NDIS_STATUS_FAILURE
(NDISUIO) Not running
LLTDIO ffffe00002e2b6b0 ffffe0000307fc10 ffffe000023e49d0
RSPNDR ffffe00002e33490 ffffe0000307e6b0 ffffe0000224e010
(RDMANDK) ffffe00002e6fc10 Declined with NDIS_STATUS_NOT_RECOGNIZED

Filter list Driver Module Context
WFP 802.3 MAC Layer LightWeight Filter-0000
ffffe00002984d70 ffffe00002e0cc70 ffffe0000300ec20
QoS Packet Scheduler-0000
ffffe00002e71750 ffffe00003003c70 ffffe00002bac180
WFP Native MAC Layer LightWeight Filter-0000
ffffe00002984ad0 ffffe00001bf5680 ffffe00003008c20

MORE INFORMATION

!minidriver ffffe00001ffaa30 -handlers !miniport ffffe00001e281a0 -offloads
!miniport ffffe00001e281a0 -pm !miniport ffffe00001e281a0 -protocoloffloads
!oid -miniport ffffe00001e281a0 !miniport ffffe00001e281a0 -timers
!pendingnbls ffffe00001e281a0
!miniport ffffe00001e281a0 -wol !miniport ffffe00001e281a0 -filterdb
!miniport ffffe00001e281a0 -rcvqueues !miniport ffffe00001e281a0 -rcvfilter
!miniport ffffe00001e281a0 -rss !miniport ffffe00001e281a0 -nicswitch
!miniport ffffe00001e281a0 -hw !miniport ffffe00001e281a0 -ss
!miniport ffffe00001e281a0 -ports !miniport ffffe00001e281a0 -wmi
0: kd> !oid -miniport ffffe00001e281a0

ALL PENDING OIDs

[Showing all OIDs on the stack for miniport ffffe00001e281a0]

No pending or queued OIDs were found.
0: kd> !pendingnbls ffffe00001e281a0

PHASE 1/3: Found 39 NBL pool(s).
PHASE 2/3: Found 82 freed NBL(s).

Pending Nbl Currently held by
No pending NBLs were found.

PHASE 3/3: Found 0 pending NBL(s) of 2130 total NBL(s).
Search complete.

0: kd> !ndiskd.mopen ffffe00001e281a0

OPEN

Ndis handle ffffe00001e281a0
Flags [Unrecognized flags 00a00280] OPEN_CLOSING,
OPEN_CALL_MANAGER, NO_BIND_REQUEST, USE_MULTICAST_LIST
References ffffe000 !mopen ffffe00001e281a0 -ref
Source Cannot load field ‘m_bindSources’ in ‘class Ndis::BindState’
Datapath state [Unreadable value]
Pause reason [Unreadable value]
Unbind reason [Unreadable value]

Protocol ffffe00002dfb3f0 - [Zero-length string]
Protocol context 00001e06

Miniport ffffe00001e281a0 - 2 - Miniport
Miniport context ffffe0000307e6b0

RECEIVE PATH

Packet filter [Unrecognized flags 00700800] ALL_MULTICAST, ALL_LOCAL
Frame Type(s) [This protocol has not registered any frame types]
Only showing the first 256 of 7324844 multicast addresses
Multicast address list 08-57-48-83-ec-20 !miniport ffffe00001e281a0 -filterdb
39-03-00-04-72-14
00-b9-1a-00-00-00
—> Has a bunch of more MAC entries

I am really clueless on what could be going wrong here. I have seen a few posts around NdisIMDeInitializeDeviceInstance in some other mailing lists but haven’t seen a solution for the same.

Jeffrey_Tippet_MSFT · November 23, 2016, 2:52pm

Can you share the callstack in NdisIMDeInitializeDeviceInstance that is hung?

What’s the breakdown of the refcounts on the miniports & open blocks? Run !miniport ffffe00001e2a1a0 -ref and !mopen ffffe00001e281a0 -ref

Are there any other interesting threads in NDIS? !stacks 2 ndis!

Shashank_Ram · November 23, 2016, 5:51pm

Hi Jeffrey, here is a trace from a different run that caused the same issue:

Call stack before NdisIMDeInitializeDeviceInstance is called:

0: kd> kn

Child-SP RetAddr Call Site

00 ffffd00023cf40b0 fffff800040cc3d2 testim!PtStopMiniport+0x40e [d:\test\protocol.c @ 1455]
01 ffffd00023cf4140 fffff80000576c17 testim!PtUnbindAdapter+0x162 [d:\test\protocol.c @ 1277]
02 ffffd00023cf41d0 fffff800005ac4e0 NDIS!ndisInvokeUnbindAdapter+0x2f
03 ffffd00023cf4210 fffff8000057757c NDIS!ndisUnbindProtocolOpen+0x168
04 ffffd00023cf4330 fffff8000056bc73 NDIS!ndisUnbindEachProtocolOpenOnMiniport+0x70
05 ffffd00023cf4370 fffff8000056d434 NDIS!Ndis::BindEngine::Iterate+0x7f3
06 ffffd00023cf4580 fffff8000056c840 NDIS!Ndis::BindEngine::UpdateBindings+0x64
07 ffffd00023cf45b0 fffff8000056d887 NDIS!Ndis::BindEngine::DispatchPendingWork+0x50
08 ffffd00023cf45e0 fffff8000057320b NDIS!Ndis::BindEngine::ApplyBindChanges+0x33
09 ffffd00023cf4630 fffff80000578378 NDIS!Ndis::BindRegistry::Reload+0x97
0a ffffd00023cf46f0 fffff8000056a185 NDIS!ndisHandleBindNotification+0x60
0b ffffd00023cf4750 fffff800005a82bc NDIS!ndisHandleUModePnPOp+0x11d
0c ffffd00023cf4790 fffff80000565d63 NDIS!ndisHandlePnPRequest+0x2ac
0d ffffd00023cf4840 fffff8006f250395 NDIS!ndisDispatchRequest+0x6f
0e ffffd00023cf4870 fffff8006f250d2a nt!IopXxxControlFile+0x845
0f ffffd00023cf4a20 fffff8006efe18b3 nt!NtDeviceIoControlFile+0x56
10 ffffd00023cf4a90 00007ff84cde7b4a nt!KiSystemServiceCopyEnd+0x13
11 000000f87c82ebc8 00007ff84a4d4b63 0x00007ff84cde7b4a 12 000000f87c82ebd0 000000020000000c 0x00007ff84a4d4b63
13 000000f87c82ebd8 0000000000000101 0x000000020000000c 14 000000f87c82ebe0 00003896275aa408 0x101 15 000000f87c82ebe8 0000000000000008 0x00003896275aa408
16 000000f87c82ebf0 000000f87c82ec20 0x8
17 000000f87c82ebf8 000000f800170008 0x000000f87c82ec20 18 000000f87c82ec00 000000f87c8c0830 0x000000f800170008
19 000000f87c82ec08 00000000000000b9 0x000000f87c8c0830 1a 000000f87c82ec10 00000000`00000000 0xb9
0: kd> !ndiskd.miniports
MiniDriver Miniport Name
ffffe000021d66e0 ffffe000036251a0 Microsoft ISATAP Adapter #2
ffffe000021d66e0 ffffe000031aa1a0 Microsoft ISATAP Adapter #3
ffffe00001c82ba0 ffffe00001c981a0 1 - Miniport
ffffe00001c82ba0 ffffe00001c901a0 2 - Miniport
ffffe000021d66e0 ffffe00001c9c1a0 Microsoft ISATAP Adapter
ffffe00000c5f810 ffffe00000c851a0 WAN Miniport (PPPOE)
ffffe00000c63020 ffffe00000c871a0 WAN Miniport (L2TP)
ffffe00002556640 ffffe00000c891a0 WAN Miniport (Network Monitor)
ffffe00000c689b0 ffffe00000c8b1a0 WAN Miniport (PPTP)
ffffe000025e2970 ffffe000017931a0 Intel(R) 82574L Gigabit Network Connection #2
ffffe00002556640 ffffe000017971a0 WAN Miniport (IPv6)
ffffe00002576740 ffffe000017991a0 Microsoft Kernel Debug Network Adapter
ffffe0000256e2e0 ffffe0000179b1a0 WAN Miniport (IKEv2)
ffffe0000256a5b0 ffffe0000179d1a0 WAN Miniport (SSTP)
ffffe00002556640 ffffe0000179f1a0 WAN Miniport (IP)

================================================================================
For “1 - Miniport”

0: kd> !miniport ffffe00001c981a0 -ref

MINIPORT REFERENCE COUNT

Tag Number of references
PNP_INITIALIZED 1
LWF_ATTACHED 3
PT_OPENED 4

!miniport ffffe00001c981a0 -ref -verbose

0: kd> !mopen ffffe00001c981a0 -ref

OPEN BLOCK REFERENCE COUNT

Tag Number of references
[Invalid refcount block]

!mopen ffffe00001c981a0 -ref -verbose

0: kd> !mopen ffffe00001c981a0

OPEN

Ndis handle ffffe00001c981a0
Flags [Unrecognized flags 00800280] OPEN_CLOSING,
OPEN_UNBINDING, OPEN_NOTIFY_PROCESSING, NO_BIND_REQUEST,
USE_MULTICAST_LIST
References ffffe000 !mopen ffffe00001c981a0 -ref
Source Cannot load field ‘m_bindSources’ in ‘class Ndis::BindState’
Datapath state [Unreadable value]
Pause reason [Unreadable value]
Unbind reason [Unreadable value]

Protocol ffffe00001cf1c00 - [Zero-length string]
Protocol context 00001e06

Miniport ffffe00001c981a0 - 1 - Miniport
Miniport context ffffe00003591c10

RECEIVE PATH

Packet filter [Unrecognized flags 00521800] ALL_MULTICAST, ALL_LOCAL,
NO_LOCAL
Frame Type(s) [This protocol has not registered any frame types]
Only showing the first 256 of 5428396 multicast addresses
Multicast address list 08-57-48-83-ec-20 !miniport ffffe00001c981a0 -filterdb
39-03-00-04-72-14
00-b9-1a-00-00-00

For “2 - Miniport”
0: kd> !miniport ffffe00001c901a0 -ref

MINIPORT REFERENCE COUNT

Tag Number of references
PNP_INITIALIZED 1
LWF_ATTACHED 3
PT_OPENED 4

!miniport ffffe00001c901a0 -ref -verbose

0: kd> !mopen ffffe00001c901a0 -ref

OPEN BLOCK REFERENCE COUNT

Tag Number of references
[Invalid refcount block]

!mopen ffffe00001c901a0 -ref -verbose

0: kd> !mopen ffffe00001c901a0

OPEN

Ndis handle ffffe00001c901a0
Flags [Unrecognized flags 00800280] OPEN_UNBINDING,
OPEN_NOTIFY_PROCESSING, NO_BIND_REQUEST,
USE_MULTICAST_LIST
References ffffe000 !mopen ffffe00001c901a0 -ref
Source Cannot load field ‘m_bindSources’ in ‘class Ndis::BindState’
Datapath state [Unreadable value]
Pause reason [Unreadable value]
Unbind reason [Unreadable value]

Protocol ffffe00001b2e400 - [Zero-length string]
Protocol context 00001e06

Miniport ffffe00001c901a0 - 2 - Miniport
Miniport context ffffe00001b39b40

RECEIVE PATH

Packet filter [Unrecognized flags 00521800] ALL_MULTICAST, ALL_LOCAL,
NO_LOCAL
Frame Type(s) [This protocol has not registered any frame types]
Only showing the first 256 of 5428396 multicast addresses
Multicast address list 08-57-48-83-ec-20 !miniport ffffe00001c901a0 -filterdb
39-03-00-04-72-14
00-b9-1a-00-00-00
—> bunch of more entries

0: kd> !stacks 2 ndis!
Proc.Thread .Thread Ticks ThreadState Blocker

Max cache size is : 1048576 bytes (0x400 KB)
Total memory in cache : 0 bytes (0 KB)
Number of regions cached: 0
0 full reads broken into 0 partial reads
counts: 0 cached/0 uncached, 0.00% cached
bytes : 0 cached/0 uncached, 0.00% cached
** Prototype PTEs are implicitly decoded
[fffff8006f1cf3c0 Idle]
[ffffe000001cd680 System]
4.0000ac ffffe00000be5040 fff6c324 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisThreadPoolTimerHandler+0x1f
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b0 ffffe00000be5880 fff49362 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeRemoveQueueEx+0x275
nt!KeRemoveQueue+0x21
NDIS!ndisWorkerThread+0x3b
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b4 ffffe00000bef880 fffffe6a Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b8 ffffe00000bf4880 fffffe6a Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16

Jeffrey_Tippet_MSFT · November 23, 2016, 8:14pm

Thanks, but I was looking for the callstack once NdisIMDeInitlaizeDeviceInstance has become hung, not before it’s called. I’m curious why it would hang.

It appears we have some bugs in the ndiskd extension. Sigh; I’ll have to get those fixed.

Shashank_Ram · November 23, 2016, 8:30pm

There have been several posts around this online, but I can’t seem to find any that was marked as resolved. Usually, when this call goes through, my MINIPORT_PAUSE gets invoked immediately. In fact, during unload, all new sends are simply completed with an NDIS_STATUS_REQUEST_ABORTED status. I am seeing this on Windows 2102 R2. Have you guys received any issues around this call? Is there something I could do to debug this further?

Shashank_Ram · November 23, 2016, 8:49pm

@Jeffrey, how can I get the callstack once NdisIMDeInitializeDeviceInstance is hung?

Shashank_Ram · November 23, 2016, 9:48pm

A hang around this call was reported in https://social.msdn.microsoft.com/Forums/windowsdesktop/en-US/84a95de2-63bf-430a-ab3b-67fbe5e11442/ndis-51-im-driver-hangs-in-ndisimdeinitializedeviceinstance?forum=wdk .

Do you happen to know if this could be a similar issue?

Shashank_Ram · November 23, 2016, 10:57pm

So it seems like the call to NDIS!ndisPnPRemoveDevice from within NdisIMDeInitializeDeviceInstance does not return.

0: kd> kn

Child-SP RetAddr Call Site

00 ffffd000237770a8 fffff800040a11e8 NDIS!NdisIMDeInitializeDeviceInstance
01 ffffd000237770b0 fffff800040a13d2 testim!PtStopMiniport+0x418 [d:\test\protocol.c @ 1457]
02 ffffd00023777140 fffff80000576c17 testim!testPtUnbindAdapter+0x162 [d:\test\protocol.c @ 1277]
03 ffffd000237771d0 fffff800005ac4e0 NDIS!ndisInvokeUnbindAdapter+0x2f
04 ffffd00023777210 fffff8000057757c NDIS!ndisUnbindProtocolOpen+0x168
05 ffffd00023777330 fffff8000056bc73 NDIS!ndisUnbindEachProtocolOpenOnMiniport+0x70
06 ffffd00023777370 fffff8000056d434 NDIS!Ndis::BindEngine::Iterate+0x7f3
07 ffffd00023777580 fffff8000056c840 NDIS!Ndis::BindEngine::UpdateBindings+0x64
08 ffffd000237775b0 fffff8000056d887 NDIS!Ndis::BindEngine::DispatchPendingWork+0x50
09 ffffd000237775e0 fffff8000057320b NDIS!Ndis::BindEngine::ApplyBindChanges+0x33
0a ffffd00023777630 fffff80000578378 NDIS!Ndis::BindRegistry::Reload+0x97
0b ffffd000237776f0 fffff8000056a185 NDIS!ndisHandleBindNotification+0x60
0c ffffd00023777750 fffff800005a82bc NDIS!ndisHandleUModePnPOp+0x11d
0d ffffd00023777790 fffff80000565d63 NDIS!ndisHandlePnPRequest+0x2ac
0e ffffd00023777840 fffff8006f250395 NDIS!ndisDispatchRequest+0x6f
0f ffffd00023777870 fffff8006f250d2a nt!IopXxxControlFile+0x845
10 ffffd00023777a20 fffff8006efe18b3 nt!NtDeviceIoControlFile+0x56
11 ffffd00023777a90 00007ff84cde7b4a nt!KiSystemServiceCopyEnd+0x13
12 000000209e90e788 00007ff84a4d4b63 0x00007ff84cde7b4a 13 000000209e90e790 000000020000000c 0x00007ff84a4d4b63
14 000000209e90e798 0000000000000101 0x000000020000000c 15 000000209e90e7a0 0000ad01221374c8 0x101 16 000000209e90e7a8 0000000000000008 0x0000ad01221374c8
17 000000209e90e7b0 000000209e90e7e0 0x8
18 000000209e90e7b8 0000002000170008 0x000000209e90e7e0 19 000000209e90e7c0 000000209e9b0830 0x0000002000170008
1a 000000209e90e7c8 00000000000000b9 0x000000209e9b0830 1b 000000209e90e7d0 0000000000000000 0xb9 0: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x5: fffff8000059c7fd 4889742410 mov qword ptr [rsp+10h],rsi
NDIS!NdisIMDeInitializeDeviceInstance+0xa:
fffff8000059c802 57 push rdi 0: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0xb: fffff8000059c803 4883ec20 sub rsp,20h
0: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0xf:
fffff8000059c807 488bd9 mov rbx,rcx 0: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x12: fffff8000059c80a bf010000c0 mov edi,0C0000001h
0: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x17:
fffff8000059c80f 803d8a9afbff04 cmp byte ptr [NDIS!ndisWppEnabledLevelPerFlag (fffff800005562a0)],4
0: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x1e:
fffff8000059c816 7214 jb NDIS!NdisIMDeInitializeDeviceInstance+0x34 (fffff8000059c82c)
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x34:
fffff8000059c82c 488bb3c80e0000 mov rsi,qword ptr [rbx+0EC8h] NDIS!NdisIMDeInitializeDeviceInstance+0x3b: fffff8000059c833 b214 mov dl,14h
NDIS!NdisIMDeInitializeDeviceInstance+0x3d:
fffff8000059c835 488bcb mov rcx,rbx NDIS!NdisIMDeInitializeDeviceInstance+0x40: fffff8000059c838 e8cf74f4ff call NDIS!ndisReferenceMiniport (fffff800004e3d0c) NDIS!NdisIMDeInitializeDeviceInstance+0x45: fffff8000059c83d 84c0 test al,al
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x47:
fffff8000059c83f 0f84bf000000 je NDIS!NdisIMDeInitializeDeviceInstance+0x10c (fffff8000059c904)

NDIS!NdisIMDeInitializeDeviceInstance+0x4d:
fffff8000059c845 33d2 xor edx,edx NDIS!NdisIMDeInitializeDeviceInstance+0x4f: fffff8000059c847 488bce mov rcx,rsi
NDIS!NdisIMDeInitializeDeviceInstance+0x52:
fffff8000059c84a e861baf4ff call NDIS!ndisReferenceDriver (fffff800004e82b0)
NDIS!NdisIMDeInitializeDeviceInstance+0x57:
fffff8000059c84f 33d2 xor edx,edx NDIS!NdisIMDeInitializeDeviceInstance+0x59: fffff8000059c851 488bcb mov rcx,rbx
NDIS!NdisIMDeInitializeDeviceInstance+0x5c:
fffff800`0059c854 c783d805000003000000 mov dword ptr [rbx+5D8h],3

1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x66:
fffff8000059c85e e861f80000 call NDIS!ndisPnPRemoveDevice (fffff800005ac0c4)

After the call to ndisPnPRemoveDevice, there is no return at all.

Shashank_Ram · November 25, 2016, 7:02pm

Has anyone else seen such an issue before? What could be going on which causes ndisPnPRemoveDevice to not return? If ndiskd tells me there are no pending NBLs and OIDs on my miniport, why does this call hang?

Shashank_Ram · November 28, 2016, 1:03pm

AFAIK, NdisIMDeInitializeDeviceInstance should not hang if there are no pending OIDs or sends. As per ndiskd’s pending OIDs and pendingNBLs output, both of these are not pending. Why else would this call hang?

Jeffrey_Tippet_MSFT · November 28, 2016, 3:11pm

NdisIMDeInitializeDeviceInstance needs to take a few locks, and it needs some refcounts to go to zero. Any of that can cause a hang. The refcounts are why OIDs & NBLs matter, but those aren’t the only things that can take references.

To get a callstack during the hang, note the thread id with “.thread”. Then hit “g” to continue execution for a moment. Finally, break in and switch back to that thread ".thread

". You should see a callstack at the point NDIS is hanging. Hopefully the callstack alone will give you a hint as to what is stuck -- whether it's a refcount or a lock.

Since your previous mail indicated that there are no other interesting threads in NDIS, I doubt it's a lock.

Shashank_Ram · November 28, 2016, 3:59pm

I don’t see anything interesting in the thread that is stuck.

0: kd> kn
*** Stack trace for last set context - .thread/.cxr resets it

Child-SP RetAddr Call Site

00 ffffd00024ddd480 fffff8006eec5b1e nt!KiSwapContext+0x76
01 ffffd00024ddd5c0 fffff8006eec55b7 nt!KiSwapThread+0x14e
02 ffffd00024ddd660 fffff8006eeee3f8 nt!KiCommitThreadWait+0x127
03 ffffd00024ddd6c0 fffff8006ef6f462 nt!KeWaitForSingleObject+0x248
04 ffffd00024ddd760 fffff80000f6ce4d nt!ExWaitForRundownProtectionReleaseCacheAware+0xaa
05 ffffd00024ddd7d0 0000000000000000 0xfffff800`00f6ce4d
0: kd> !stacks 2 ndis!
Proc.Thread .Thread Ticks ThreadState Blocker

Max cache size is : 1048576 bytes (0x400 KB)
Total memory in cache : 0 bytes (0 KB)
Number of regions cached: 0
0 full reads broken into 0 partial reads
counts: 0 cached/0 uncached, 0.00% cached
bytes : 0 cached/0 uncached, 0.00% cached
** Prototype PTEs are implicitly decoded
[fffff8006f1cf3c0 Idle]
[ffffe000001cd680 System]
4.0000ac ffffe00000be5040 fff6c324 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisThreadPoolTimerHandler+0x1f
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b0 ffffe00000be5880 fff44a9c Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeRemoveQueueEx+0x275
nt!KeRemoveQueue+0x21
NDIS!ndisWorkerThread+0x3b
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b4 ffffe00000bef880 fffffe6a Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000b8 ffffe00000bf4880 fffffe6a Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16

NDIS!NdisIMDeInitializeDeviceInstance:
fffff8000059c7f8 48895c2408 mov qword ptr [rsp+8],rbx NDIS!NdisIMDeInitializeDeviceInstance+0x5: fffff8000059c7fd 4889742410 mov qword ptr [rsp+10h],rsi
NDIS!NdisIMDeInitializeDeviceInstance+0xa:
fffff8000059c802 57 push rdi NDIS!NdisIMDeInitializeDeviceInstance+0xb: fffff8000059c803 4883ec20 sub rsp,20h
NDIS!NdisIMDeInitializeDeviceInstance+0xf:
fffff8000059c807 488bd9 mov rbx,rcx NDIS!NdisIMDeInitializeDeviceInstance+0x12: fffff8000059c80a bf010000c0 mov edi,0C0000001h
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x17:
fffff8000059c80f 803d8a9afbff04 cmp byte ptr [NDIS!ndisWppEnabledLevelPerFlag (fffff800005562a0)],4
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x1e:
fffff8000059c816 7214 jb NDIS!NdisIMDeInitializeDeviceInstance+0x34 (fffff8000059c82c)
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x34:
fffff8000059c82c 488bb3c80e0000 mov rsi,qword ptr [rbx+0EC8h] 1: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x3b: fffff8000059c833 b214 mov dl,14h
1: kd> p
NDIS!NdisIMDeInitializeDeviceInstance+0x3d:
fffff8000059c835 488bcb mov rcx,rbx 1: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x40: fffff8000059c838 e8cf74f4ff call NDIS!ndisReferenceMiniport (fffff800004e3d0c) 1: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x45: fffff8000059c83d 84c0 test al,al
NDIS!NdisIMDeInitializeDeviceInstance+0x47:
fffff8000059c83f 0f84bf000000 je NDIS!NdisIMDeInitializeDeviceInstance+0x10c (fffff8000059c904)
NDIS!NdisIMDeInitializeDeviceInstance+0x4d:
fffff8000059c845 33d2 xor edx,edx NDIS!NdisIMDeInitializeDeviceInstance+0x4f: fffff8000059c847 488bce mov rcx,rsi
NDIS!NdisIMDeInitializeDeviceInstance+0x52:
fffff8000059c84a e861baf4ff call NDIS!ndisReferenceDriver (fffff800004e82b0)
NDIS!NdisIMDeInitializeDeviceInstance+0x57:
fffff8000059c84f 33d2 xor edx,edx NDIS!NdisIMDeInitializeDeviceInstance+0x59: fffff8000059c851 488bcb mov rcx,rbx
NDIS!NdisIMDeInitializeDeviceInstance+0x5c:
fffff8000059c854 c783d805000003000000 mov dword ptr [rbx+5D8h],3 1: kd\> p NDIS!NdisIMDeInitializeDeviceInstance+0x66: fffff8000059c85e e861f80000 call NDIS!ndisPnPRemoveDevice (fffff800`005ac0c4)

Any idea why NDIS!ndisPnPRemoveDevice could not return?

Shashank_Ram · November 28, 2016, 8:34pm

Are there any specific things I could look at to debug this further?

Shashank_Ram · November 29, 2016, 1:02pm

I have the following questions:

Is the ndiskd pendingnbls and oid command reliable? I am maintaining my own counters too but just want to ensure its reliable enough.
If the above is reliable, what else could cause NdisIMDeInitializeDeviceInstance to not return?
Looks like it is waiting on some event. What event does it wait for?
What is the best way to debug this further?

Shashank_Ram · November 29, 2016, 4:57pm

I managed to get much more debugging info this time when this happened:

=================================================================================
1: kd> !ndiskd.miniports
MiniDriver Miniport Name
ffffe000028d3020 ffffe000031a81a0 Microsoft ISATAP Adapter #3
ffffe00001ba1200 ffffe000017f91a0 1 - Miniport
ffffe000028d3020 ffffe000031001a0 Microsoft ISATAP Adapter
ffffe00002fca020 ffffe00002fd01a0 WAN Miniport (PPPOE)
ffffe00002fbfba0 ffffe00002fc41a0 WAN Miniport (L2TP)
ffffe00002e862a0 ffffe00002fc21a0 WAN Miniport (Network Monitor)
ffffe00002fbf020 ffffe00002fc01a0 WAN Miniport (PPTP)
ffffe00002f02ba0 ffffe00002fae1a0 Intel(R) 82574L Gigabit Network Connection #2
ffffe00002e862a0 ffffe00002f8c1a0 WAN Miniport (IPv6)
ffffe00002eaa530 ffffe00002f8a1a0 Microsoft Kernel Debug Network Adapter
ffffe00002ea2220 ffffe00002f871a0 WAN Miniport (IKEv2)
ffffe00002e9e150 ffffe00002f6f1a0 WAN Miniport (SSTP)
ffffe00002e862a0 ffffe00002f6d1a0 WAN Miniport (IP)
1: kd> !ndiskd.miniport ffffe000017f91a0

MINIPORT

1 - Miniport

Ndis handle ffffe000017f91a0
Ndis API version v6.30
Adapter context ffffcf8003f9cc00
Miniport driver ffffe00001ba1200 - testIMMP v1.0
Network interface ffffcf8002aa6a20

Media type 802.3
Device instance ROOT\testIMMP\0000
Device object ffffe000017f9050 !miniport ffffe000017f91a0 -device
MAC address 00-0c-29-f8-34-9c

STATE

Miniport Running
Device PnP STOPPED !miniport ffffe000017f91a0 -log
Datapath Normal
Interface Up
Media Connected
Power D0
References 9 !miniport ffffe000017f91a0 -ref
Total resets 0
Pending OID None
Flags NOT_BUS_MASTER, INTERMEDIATE_DRIVER,
DEFAULT_PORT_ACTIVATED, NOT_RESOURCES_AVAILABLE,
SUPPORTS_MEDIA_SENSE, DOES_NOT_DO_LOOPBACK,
MEDIA_CONNECTED
PnP flags PM_SUPPORTED, DEVICE_POWER_ENABLED, NO_HALT_ON_SUSPEND,
RECEIVED_START

BINDINGS

Protocol list Driver Open Context
(RDMANDK) ffffcf80004bac10 Declined with NDIS_STATUS_NOT_RECOGNIZED
TCPIP ffffcf8000446c10 ffffcf8004348c10 ffffe00002948330
TCPIP6 ffffcf8000450c10 ffffcf8004316c10 ffffe000028d1010
RSPNDR ffffcf800418cc10 ffffcf800404cc10 ffffcf80043586a0
LLTDIO ffffcf8004176c10 ffffcf8003dd0c10 ffffcf8003fbcd40
(NDISUIO) Not running
(RASPPPOE) ffffcf80007c8c10 Declined with NDIS_STATUS_FAILURE

Filter list Driver Module Context
WFP 802.3 MAC Layer LightWeight Filter-0000
ffffcf8000496d70 ffffcf800422cc70 ffffe000031256e0
QoS Packet Scheduler-0000
ffffcf80004d4d90 ffffcf80045d0c70 ffffcf8003f8ef20
WFP Native MAC Layer LightWeight Filter-0000
ffffcf80004a0d70 ffffcf800443ec70 ffffe000030b0610

1: kd> !oid -miniport ffffe000017f91a0

ALL PENDING OIDs

[Showing all OIDs on the stack for miniport ffffe000017f91a0]

No pending or queued OIDs were found.
1: kd> !pendingnbls ffffe000017f91a0

PHASE 1/3: Found 38 NBL pool(s).
A timeout occurred. The timeout can be increased in the Debugging options page
PHASE 2/3: Found 0 freed NBL(s).

Pending Nbl Currently held by
No pending NBLs were found.

PHASE 3/3: Found 0 pending NBL(s) of 2048 total NBL(s).

Output of “!stacks 2 ndis!”

1: kd> !stacks 2 ndis!
Proc.Thread .Thread Ticks ThreadState Blocker

Max cache size is : 1048576 bytes (0x400 KB)
Total memory in cache : 0 bytes (0 KB)
Number of regions cached: 0
0 full reads broken into 0 partial reads
counts: 0 cached/0 uncached, 0.00% cached
bytes : 0 cached/0 uncached, 0.00% cached
** Prototype PTEs are implicitly decoded
[fffff8014815a3c0 Idle]
[ffffe000000a2400 System]
4.0000ec ffffe00001d94040 fffffe42 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
nt!VerifierKeWaitForSingleObject+0x15c
NDIS!ndisThreadPoolTimerHandler+0x1f
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000f0 ffffe00001d94880 ffffb252 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeRemoveQueueEx+0x275
nt!KeRemoveQueue+0x21
NDIS!ndisWorkerThread+0x3b
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000f4 ffffe00001d99880 fffffe40 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
nt!VerifierKeWaitForSingleObject+0x15c
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
4.0000f8 ffffe00001d9e880 fffffe40 Blocked nt!KiSwapContext+0x76
nt!KiSwapThread+0x14e
nt!KiCommitThreadWait+0x127
nt!KeWaitForSingleObject+0x248
nt!VerifierKeWaitForSingleObject+0x15c
NDIS!ndisReceiveWorkerThread+0xa8
nt!PspSystemThreadStartup+0x58
nt!KiStartSystemThread+0x16
47c.000a50 ffffe00002b1a640 ffffb142 RUNNING nt!memset+0xc0
nt!MmAllocateSpecialPool+0x406
nt! ?? ::FNODOBFM::`string’+0x36db
nt!VeAllocatePoolWithTagPriority+0x1d6
nt!IovAllocateMdl+0x59
VerifierExt!XdvHibernationNotification+0x6c8f
nt!VerifierIoAllocateMdl+0x2a
NDIS!NdisAllocateMdl+0x20
kdnic!HWFrameAllocate+0x43
kdnic!RxReceiveIndicateDpc+0x74
nt!KiRetireDpcList+0x6b2
nt!KxRetireDpcList+0x5
nt!KiDispatchInterruptContinue
nt!KiDpcInterruptBypass+0x25
nt!KiInterruptDispatchLBControl+0x197
msvcrt!memcmp+0x52

–> Below is our stuck thread

abc.000ca8 ffffe000030f6880 ffffb11f RUNNING NDIS!NdisIMDeInitializeDeviceInstance+0x66
testim!PtStopMiniport+0x418
testim!PtUnbindAdapter+0x162
NDIS!ndisInvokeUnbindAdapter+0x2f
NDIS!ndisUnbindProtocolOpen+0x168
NDIS!ndisUnbindEachProtocolOpenOnMiniport+0x70
NDIS!Ndis::BindEngine::Iterate+0x7f3
NDIS!Ndis::BindEngine::UpdateBindings+0x64
NDIS!Ndis::BindEngine::DispatchPendingWork+0x50
NDIS!Ndis::BindEngine::ApplyBindChanges+0x33
NDIS!Ndis::BindRegistry::Reload+0x97
NDIS!ndisHandleBindNotification+0x60
NDIS!ndisHandleUModePnPOp+0x11d
NDIS!ndisHandlePnPRequest+0x2ac
NDIS!ndisDispatchRequest+0x6f
nt!IovCallDriver+0x3cd
nt!IopXxxControlFile+0x845
nt!NtDeviceIoControlFile+0x56
nt!KiSystemServiceCopyEnd+0x13
ntdll!NtDeviceIoControlFile+0xa
KERNELBASE!DeviceIoControl+0x73
KERNEL32!DeviceIoControl+0x80
netcfgx!OnMachineUILanguageSwitch+0x32460
+0xb9
+0xb54e165650
+0x20c
+0xb54e165650

===========================================================================
Stack of the thread that is currently stuck.
0: kd> kn
*** Stack trace for last set context - .thread/.cxr resets it

Child-SP RetAddr Call Site

00 ffffd00022d2a430 fffff80147e50b1e nt!KiSwapContext+0x76
01 ffffd00022d2a570 fffff80147e505b7 nt!KiSwapThread+0x14e
02 ffffd00022d2a610 fffff80147e793f8 nt!KiCommitThreadWait+0x127
03 ffffd00022d2a670 fffff80147efa462 nt!KeWaitForSingleObject+0x248
04 ffffd00022d2a710 fffff80001138e4d nt!ExWaitForRundownProtectionReleaseCacheAware+0xaa
05 ffffd00022d2a780 fffff8000076176e tcpip!FlPnpEvent+0x1c5
06 ffffd00022d2a7f0 fffff800007616d3 NDIS!ndisInvokeNetPnPEvent+0x42
07 ffffd00022d2a830 fffff8000079d84a NDIS!ndisDeliverNetPnPEventSynchronously+0x47
08 ffffd00022d2a870 fffff800007618f5 NDIS!ndisPnPNotifyBinding+0x86
09 ffffd00022d2a990 fffff8000076a9cb NDIS!ndisPnPNotifyBindingUnlocked+0x35
0a ffffd00022d2a9e0 fffff8000076a89f NDIS!ndisPauseProtocolInner+0x6b
0b ffffd00022d2aae0 fffff8000075f776 NDIS!ndisPauseProtocol+0x5f
0c ffffd00022d2ab20 fffff80000761434 NDIS!Ndis::BindEngine::Iterate+0x2f6
0d ffffd00022d2ad30 fffff80000760840 NDIS!Ndis::BindEngine::UpdateBindings+0x64
0e ffffd00022d2ad60 fffff80000761887 NDIS!Ndis::BindEngine::DispatchPendingWork+0x50
0f ffffd00022d2ad90 fffff800007a024f NDIS!Ndis::BindEngine::ApplyBindChanges+0x33
10 ffffd00022d2ade0 fffff80000790863 NDIS!ndisPnPRemoveDevice+0x18b
11 ffffd00022d2b030 fffff80003140248 NDIS!NdisIMDeInitializeDeviceInstance+0x6b
12 ffffd00022d2b060 fffff80003140432 testim!PtStopMiniport+0x418 [d:\test\protocol.c @ 1460]
13 ffffd00022d2b0f0 fffff8000076ac17 testim!PtUnbindAdapter+0x162 [d:\test\protocol.c @ 1280]
14 ffffd00022d2b180 fffff800007a04e0 NDIS!ndisInvokeUnbindAdapter+0x2f
15 ffffd00022d2b1c0 fffff8000076b57c NDIS!ndisUnbindProtocolOpen+0x168
16 ffffd00022d2b2e0 fffff8000075fc73 NDIS!ndisUnbindEachProtocolOpenOnMiniport+0x70
17 ffffd00022d2b320 fffff80000761434 NDIS!Ndis::BindEngine::Iterate+0x7f3
18 ffffd00022d2b530 fffff80000760840 NDIS!Ndis::BindEngine::UpdateBindings+0x64
19 ffffd00022d2b560 fffff80000761887 NDIS!Ndis::BindEngine::DispatchPendingWork+0x50
1a ffffd00022d2b590 fffff8000076720b NDIS!Ndis::BindEngine::ApplyBindChanges+0x33
1b ffffd00022d2b5e0 fffff8000076c378 NDIS!Ndis::BindRegistry::Reload+0x97
1c ffffd00022d2b6a0 fffff8000075e185 NDIS!ndisHandleBindNotification+0x60
1d ffffd00022d2b700 fffff8000079c2bc NDIS!ndisHandleUModePnPOp+0x11d
1e ffffd00022d2b740 fffff80000759d63 NDIS!ndisHandlePnPRequest+0x2ac
1f ffffd00022d2b7f0 fffff80148474911 NDIS!ndisDispatchRequest+0x6f
20 ffffd00022d2b820 fffff801481db395 nt!IovCallDriver+0x3cd
21 ffffd00022d2b870 fffff801481dbd2a nt!IopXxxControlFile+0x845
22 ffffd00022d2ba20 fffff80147f6c8b3 nt!NtDeviceIoControlFile+0x56
23 ffffd00022d2ba90 00007ffb6acf7b4a nt!KiSystemServiceCopyEnd+0x13
24 000000b54df7e798 0000000000000000 ntdll!NtDeviceIoControlFile+0xa

Looking at the stack trace, it is clear that tcpip!FlPnpEvent is waiting on some event. This seems strange since at that point there were no NBLs or OIDs pending on the miniport.

I hope the above stack will help shed some light on whats going on here.

Shashank_Ram · December 1, 2016, 10:50pm

Looking at my counters, it seems like I do not have any pending OIDs or Sends. Can pending receives also result in this hang?

What else can I look at to debug this?

Shashank_Ram · December 8, 2016, 3:58pm

I have managed to resolve this issue. There was a bug in my driver where sometimes, for a packet sent by TCP/IP to my Miniport’s SendNetBufferList funcion, I would modify the NBL’s SourceHandle and not correctly reset it back. Once I fixed this issue, I haven’t seen an issue with driver unload.

On a side note, it would have been great had “ndiskd.pendingnbls” caught the issue somehow.