Device not unloaded after surprise removal

NTDEV
1

Hi.

I have the following problem:
I have a COM port device which is installed as a modem. Sometimes, after performing a dial up and then a surprise removal, the device is not unloaded, and I see that that the dial up icon stays connected.

Here is an output that I got from some WinDbg commands when trying to debug this:

!wdfkd.wdfdevice 76CE3970 fff
Dumping WDFDEVICE 0x76909fb0

WDM PDEVICE_OBJECTs:self 89319f00, attached 8a756f00, pdo 8a756f00

Pnp state: 12e ( WdfDevStatePnpFailedWaitForRemove )
Power state: 315 ( WdfDevStatePowerStopped )
Power Pol state: 563 ( WdfDevStatePwrPolStopped )

Default WDFIOTARGET: 76ce6200

No pended pnp or power irps
Device is the power policy owner for the stack

Pnp state history:
[0] WdfDevStatePnpHardwareAvailable (0x108)
[1] WdfDevStatePnpEnableInterfaces (0x109)
[2] WdfDevStatePnpStarted (0x119)
[3] WdfDevStatePnpSurpriseRemoveIoStarted (0x127)
[4] WdfDevStatePnpFailedIoStarting (0x129)
[5] WdfDevStatePnpFailedOwnHardware (0x12a)
[6] WdfDevStatePnpFailed (0x12b)
[7] WdfDevStatePnpFailedWaitForRemove (0x12e)

Power state history:
[0] WdfDevStatePowerD0Starting (0x30f)
[1] WdfDevStatePowerD0StartingConnectInterrupt (0x310)
[2] WdfDevStatePowerD0StartingDmaEnable (0x311)
[3] WdfDevStatePowerD0StartingStartSelfManagedIo (0x312)
[4] WdfDevStatePowerDecideD0State (0x313)
[5] WdfDevStatePowerD0 (0x307)
[6] WdfDevStatePowerGotoD3Stopped (0x314)
[7] WdfDevStatePowerStopped (0x315)

Power policy state history:
[0] WdfDevStatePwrPolObjectCreated (0x500)
[1] WdfDevStatePwrPolStarting (0x501)
[2] WdfDevStatePwrPolStartingSucceeded (0x502)
[3] WdfDevStatePwrPolStartingDecideS0Wake (0x504)
[4] WdfDevStatePwrPolStarted (0x565)
[5] WdfDevStatePwrPolStopping (0x55b)
[6] WdfDevStatePwrPolStoppingSendStatus (0x55d)
[7] WdfDevStatePwrPolStopped (0x563)

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

0: kd> !wdfkd.wdfdevicequeues 76909FB0

Dumping queues of WDFDEVICE 0x76909fb0

Number of queues: 8

Queue: 1 (!wdfqueue 0x765682f8)
Manual, Not power-managed, PowerOn, Can accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

This is WDF internal queue for create requests.

Queue: 2 (!wdfqueue 0x7681a1e8)
Parallel, Default, Not power-managed, PowerOn, Can accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoRead: (0xa7148590)
EvtIoDeviceControl: (0xa7146410)
EvtIoInternalDeviceControl: (0xa7147a00)
EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 3 (!wdfqueue 0x762591e8)
Parallel, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoWrite: (0xa7149bf0)
EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 4 (!wdfqueue 0x765e3f08)
Manual, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 5 (!wdfqueue 0x7690bfb0)
Manual, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 6 (!wdfqueue 0x76953fb0)
Manual, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 7 (!wdfqueue 0x76bd4fb0)
Manual, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

EvtIoCanceledOnQueue: (0xa7145f60)

Queue: 8 (!wdfqueue 0x767cdfb0)
Manual, Power-managed, PowerOff, Cannot accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0

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

0: kd> !devnode 8a756f00
DevNode 0x8a756f00 for PDO 0000000000
Parent 0x893d7c80 Sibling 0x00d00003 Child 0x00000001
InterfaceType 0x10000 Bus Number 0x8a756fd0
InstancePath is ""
TargetDeviceNotify List - f 0x00040001 b 0000000000
State = Unknown State (0x0)
Previous State = Unknown State (0x3044)
StateHistory[19] = Unknown State (0x0)
StateHistory[18] = Unknown State (0x8a756f64)
StateHistory[17] = Unknown State (0x8a756f64)
StateHistory[16] = Unknown State (0x140014)
StateHistory[15] = Unknown State (0x0)
StateHistory[14] = Unknown State (0x0)
StateHistory[13] = Unknown State (0x0)
StateHistory[12] = Unknown State (0x0)
StateHistory[11] = Unknown State (0x0)
StateHistory[10] = Unknown State (0x0)
StateHistory[09] = Unknown State (0x0)
StateHistory[08] = Unknown State (0x0)
StateHistory[07] = Unknown State (0x0)
StateHistory[06] = Unknown State (0x0)
StateHistory[05] = Unknown State (0x0)
StateHistory[04] = Unknown State (0x1)
StateHistory[03] = Unknown State (0x2b)
StateHistory[02] = Unknown State (0x896ee210)
StateHistory[01] = Unknown State (0x0)
StateHistory[00] = Unknown State (0x180)
Flags (0000000000)
DisableableDepends = 168296448 (from children)

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

0: kd> !devhandles 8a756f00

Checking handle table for process 0x8a979a00
Handle table at e1f06000 with 392 Entries in use

Checking handle table for process 0x89ed42f0
Handle table at e1c34000 with 19 Entries in use

Checking handle table for process 0x89f39ae8
Handle table at e35ba000 with 490 Entries in use

Checking handle table for process 0x8a1f6da0
Handle table at e2dcc000 with 588 Entries in use

Checking handle table for process 0x8a1fe228
Handle table at e2be2000 with 305 Entries in use

Checking handle table for process 0x8a1ba650
Handle table at e2bf6000 with 373 Entries in use

Checking handle table for process 0x89f46200
Handle table at e2d69000 with 212 Entries in use

Checking handle table for process 0x8a4cf2d8
Handle table at e2d98000 with 353 Entries in use

Checking handle table for process 0x8a647da0
Handle table at e3326000 with 1888 Entries in use
PROCESS 8a647da0 SessionId: 0 Cid: 0354 Peb: 7ffdc000 ParentCid: 0228
DirBase: 0af00120 ObjectTable: e2d27d38 HandleCount: 1888.
Image: svchost.exe

2824: Object: 896613a0 GrantedAccess: 0012019f

Checking handle table for process 0x89ed3880
Handle table at e2da5000 with 95 Entries in use

Checking handle table for process 0x89ecb4d8
Handle table at e2dac000 with 182 Entries in use

Checking handle table for process 0x89f1ada0
Handle table at e2f46000 with 149 Entries in use

Checking handle table for process 0x8a4c6c08
Handle table at e3056000 with 90 Entries in use

Checking handle table for process 0x8a611020
Handle table at e3069000 with 51 Entries in use

Checking handle table for process 0x8a7995d8
Handle table at e1fe5000 with 82 Entries in use

Checking handle table for process 0x89ec7020
Handle table at e2bbf000 with 189 Entries in use

Checking handle table for process 0x89f3e468
00000000: Unable to read handle table

Thanks,
S.

2

Does your device get IRP_MN_REMOVE_DEVICE? I don’t see it in your trace.
If it doesn’t, it is likely that your driver still has an open handle.

Igor Sharovar

3

Hi Igor.
Thank you for you response.
You are right, examining my driver’s logs again shows that EvtFileCleanup and EvtFileClose callbacks were not executed.
The question is, what prevents Windows dial up application from closing the file handle and what can I do to debug it?

Thanks,
S.

4

Has all pended io been purged with an error indicating the device is gone? Do you use any non pwr managed queues? Pwr managed queues will automatically be flushed on surprise removal, non pwr managed are flushed automatically on remove

d

Sent from my phone with no t9, all spilling mistakes are not intentional.

-----Original Message-----
From: xxxxx@gmail.com
Sent: Thursday, September 24, 2009 12:18 AM
To: Windows System Software Devs Interest List
Subject: RE:[ntdev] Device not unloaded after surprise removal

Hi Igor.
Thank you for you response.
You are right, examining my driver’s logs again shows that EvtFileCleanup and EvtFileClose callbacks were not executed.
The question is, what prevents Windows dial up application from closing the file handle and what can I do to debug it?

Thanks,
S.

—
NTDEV is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

5

Hi Doron.

All pending request are completed with STATUS_CANCELED. All requests that arrive later on are completed immediately with status STATUS_DELETE_PENDING. Output of !wdfkd.wdfdevicequeues command also shows that there are no pending requests.

I have both power managed and non power managed queues in the driver. I also have 4 manual queues which are purged upon device removal.

Using IrpTracker, I noticed that when the driver does not unload, IRP_MJ_CLEANUP isn’t sent. I don’t know whether it is caused by a dial up application bug which does not close the file handle, ore somewhere else.

Thanks,
S.

6

You could check in your driver if its CLOSE dispatch routine is called (IRP_MJ_CLOSE). You could put a a variable in your ether DriverExtention struct or allocate as a global to count all Open(IRP_MJ_CREATE) and Close ( IRP_MJ_CLOSE). On each Open call you should get one Close. If you will have more Open calls then lose it means that you have outstanding open handles.

Igor Sharovar

7

You need to purge all queues upon IRP_MJ_CLEANUP and NP/IRP_MN_SURPRISE_REMOVAL, too. Otherwise you’ll never get CLOSE and REMOVE_DEVICE.

8

Igor,
I don’t get IRP_MJ_CLOSE. I verified this with Irp Tracker. I also verified that EvtFileCleanup and EvtFileClose (which are executed for IRP_MJ_CLEANUP and IRP_MJ_CLOSED respectively) aren’t called.

Alex,
I do get REMOVE_DEVICE, but I don’t get IRP_MJ_CLEANUP and IRP_MJ_CLOSE.
I am purging the manual queues, am I supposed to purge the framework queues as well? Aren’t they purged automatically by the framework?

Thanks,
S.

9

>I am purging the manual queues, am I supposed to purge the framework >queues as well? Aren’t they purged automatically by the framework?
Doron already answered on this question before
“Pwr managed queues will automatically be flushed on surprise removal, non pwr managed are flushed automatically on remove”

Igor Sharovar

10

If you did not receive a cleanup or close and there is still and pen handle, there is no way you got a remove irp. You will get a surprise removal irp and stay stuck in the surprise removed state (perhaps indefinitely until reboot) until the handle is closed

d

Sent from my phone with no t9, all spilling mistakes are not intentional.

-----Original Message-----
From: xxxxx@gmail.com
Sent: Tuesday, September 29, 2009 2:21 AM
To: Windows System Software Devs Interest List
Subject: RE:[ntdev] Device not unloaded after surprise removal

Igor,
I don’t get IRP_MJ_CLOSE. I verified this with Irp Tracker. I also verified that EvtFileCleanup and EvtFileClose (which are executed for IRP_MJ_CLEANUP and IRP_MJ_CLOSED respectively) aren’t called.

Alex,
I do get REMOVE_DEVICE, but I don’t get IRP_MJ_CLEANUP and IRP_MJ_CLOSE.
I am purging the manual queues, am I supposed to purge the framework queues as well? Aren’t they purged automatically by the framework?

Thanks,
S.

—
NTDEV is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer