IRP_MN_REMOVE_DEVICE and bus relations

We’re developping a USB bus driver that creates 3 child PDO that act as serial port with their own driver. We’re trying to gain WHQL validation and currently fail tne PnP test when it tests the IRP_MN_REMOVE_DEVICE on the serial driver. Here is the result we get fro the driver verifier:

OurSer - fdo 0x896CE8C8 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89B5F5C0 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89B5F5C0
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89D9A2C0
OurSer - fdo 0x89A8AC88 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89D9A2C0 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89D9A2C0
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89D951A8
OurUsb - fdo 0x89BA3DA8 - PNP Request (IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000004 for stack with PDO 0x89D951A8
PNPFILTR: Received IRP_MN_REMOVE_DEVICE for stack with PDO 0x89B012B8
OurSer - fdo 0x89724030 - PNP Request ( IRP_MN_REMOVE_DEVICE -> HandleRemoveDevice )
OurSer - fdo 0x89724030 - Disabling device interface
OurSer - fdo 0x89724030 - To REMOVED from PENDINGREMOVE
OurUsb - pdo 0x89B012B8 - PNP Request( IRP_MN_REMOVE_DEVICE)

***********************************************************************
* THIS VALIDATION BUG IS FATAL AND WILL CAUSE THE VERIFIER TO HALT *
* WINDOWS (BUGCHECK) WHEN THE MACHINE IS NOT UNDER A KERNEL DEBUGGER! *
***********************************************************************

WDM DRIVER ERROR: [ourusb.sys @ 0xAD0E17B0] An IRP dispatch handler for a
PDO has deleted it’s device object, but the hardware has
not been reported as missing in a bus relations query.
DeviceObject = 89B012B8 - Dispatch = AD0E17B0 - Irp =
8AE90F20
IRP_MJ_PNP.IRP_MN_REMOVE_DEVICE -

We’ve compared to what the toaster DDK example does and we seem to be doing the same actions, but obviously we must be missing something. In the serial driver, we do:

// This IRP must never fail
Irp->IoStatus.Status = STATUS_SUCCESS;

if( NT_SUCCESS( IoAcquireRemoveLock( &pdx->RemoveLock, Irp ) ) )
{
// Cancel any queued IRPs and start rejecting new ones
AbortRequests(&pdx->dqRead, STATUS_DELETE_PENDING);

// Disable all device interfaces. This triggers PnP notifications that will allow apps to close their handles.
DeregisterAllInterfaces( pdx );

DumpDebug( DBG_PNP, ( DRIVERNAME " - fdo 0x%X - To REMOVED from %s\n", fdo, statenames[pdx->state]) );
pdx->state = REMOVED;

// Let lower-level drivers handle this request. Ignore whatever result eventuates.
DefaultPnpHandler( fdo, Irp );

// Wait for all claims against this device to vanish before removing the device object.
IoReleaseRemoveLockAndWait( &pdx->RemoveLock, Irp );

// Remove the device object
RemoveDevice( fdo );
}

return STATUS_SUCCESS; // lower-level completed IoStatus already

The failure occurs in DefaultPnpHandler() which simply send the IRP to the lower device, which is our USB driver:

IoSkipCurrentIrpStackLocation( Irp );

PSERIAL_DEVICE_EXTENSION pdx = (PSERIAL_DEVICE_EXTENSION) fdo->DeviceExtension;
NTSTATUS Status = STATUS_SUCCESS;

if( pdx->LowerDeviceObject )
Status = IoCallDriver( pdx->LowerDeviceObject, Irp );

In the USB driver, we simply succeed the IRP:

case IRP_MN_REMOVE_DEVICE:
DumpDebug( DBG_PNPPDO, (DRIVERNAME " - pdo 0x%X - PNP Request( IRP_MN_REMOVE_DEVICE)\n",pdo) );
status = PdoSucceedRequest(pdo,Irp );

And PdoSucceedRequest() does as its name implies:

Irp->IoStatus.Status = STATUS_SUCCESS;
IoCompleteRequest ( Irp, IO_NO_INCREMENT );

Any help about what we are doing wrong?

Are you sure you are not deleting the PDO in the bus driver? Also, if you are just developing this bus driver I strongly suggest that you use KMDF instead. You will get all of the pnp/bus driver logic for free (which passes pnpdest and whql as is) and you can focus in on your company’s value add

d

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@hotmail.com
Sent: Tuesday, December 16, 2008 12:03 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] IRP_MN_REMOVE_DEVICE and bus relations

We’re developping a USB bus driver that creates 3 child PDO that act as serial port with their own driver. We’re trying to gain WHQL validation and currently fail tne PnP test when it tests the IRP_MN_REMOVE_DEVICE on the serial driver. Here is the result we get fro the driver verifier:

OurSer - fdo 0x896CE8C8 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89B5F5C0 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89B5F5C0
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89D9A2C0
OurSer - fdo 0x89A8AC88 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89D9A2C0 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89D9A2C0
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89D951A8
OurUsb - fdo 0x89BA3DA8 - PNP Request (IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000004 for stack with PDO 0x89D951A8
PNPFILTR: Received IRP_MN_REMOVE_DEVICE for stack with PDO 0x89B012B8
OurSer - fdo 0x89724030 - PNP Request ( IRP_MN_REMOVE_DEVICE -> HandleRemoveDevice )
OurSer - fdo 0x89724030 - Disabling device interface
OurSer - fdo 0x89724030 - To REMOVED from PENDINGREMOVE
OurUsb - pdo 0x89B012B8 - PNP Request( IRP_MN_REMOVE_DEVICE)

***********************************************************************
* THIS VALIDATION BUG IS FATAL AND WILL CAUSE THE VERIFIER TO HALT *
* WINDOWS (BUGCHECK) WHEN THE MACHINE IS NOT UNDER A KERNEL DEBUGGER! *
***********************************************************************

WDM DRIVER ERROR: [ourusb.sys @ 0xAD0E17B0] An IRP dispatch handler for a
PDO has deleted it’s device object, but the hardware has
not been reported as missing in a bus relations query.
DeviceObject = 89B012B8 - Dispatch = AD0E17B0 - Irp =
8AE90F20
IRP_MJ_PNP.IRP_MN_REMOVE_DEVICE -

We’ve compared to what the toaster DDK example does and we seem to be doing the same actions, but obviously we must be missing something. In the serial driver, we do:

// This IRP must never fail
Irp->IoStatus.Status = STATUS_SUCCESS;

if( NT_SUCCESS( IoAcquireRemoveLock( &pdx->RemoveLock, Irp ) ) )
{
// Cancel any queued IRPs and start rejecting new ones
AbortRequests(&pdx->dqRead, STATUS_DELETE_PENDING);

// Disable all device interfaces. This triggers PnP notifications that will allow apps to close their handles.
DeregisterAllInterfaces( pdx );

DumpDebug( DBG_PNP, ( DRIVERNAME " - fdo 0x%X - To REMOVED from %s\n", fdo, statenames[pdx->state]) );
pdx->state = REMOVED;

// Let lower-level drivers handle this request. Ignore whatever result eventuates.
DefaultPnpHandler( fdo, Irp );

// Wait for all claims against this device to vanish before removing the device object.
IoReleaseRemoveLockAndWait( &pdx->RemoveLock, Irp );

// Remove the device object
RemoveDevice( fdo );
}

return STATUS_SUCCESS; // lower-level completed IoStatus already

The failure occurs in DefaultPnpHandler() which simply send the IRP to the lower device, which is our USB driver:

IoSkipCurrentIrpStackLocation( Irp );

PSERIAL_DEVICE_EXTENSION pdx = (PSERIAL_DEVICE_EXTENSION) fdo->DeviceExtension;
NTSTATUS Status = STATUS_SUCCESS;

if( pdx->LowerDeviceObject )
Status = IoCallDriver( pdx->LowerDeviceObject, Irp );

In the USB driver, we simply succeed the IRP:

case IRP_MN_REMOVE_DEVICE:
DumpDebug( DBG_PNPPDO, (DRIVERNAME " - pdo 0x%X - PNP Request( IRP_MN_REMOVE_DEVICE)\n",pdo) );
status = PdoSucceedRequest(pdo,Irp );

And PdoSucceedRequest() does as its name implies:

Irp->IoStatus.Status = STATUS_SUCCESS;
IoCompleteRequest ( Irp, IO_NO_INCREMENT );

Any help about what we are doing wrong?


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

Yes, I’m pretty sure of it. The whole code, unrolled would look like this (cut n paste):

PCOMMON_EXTENSION pcx = (PCOMMON_EXTENSION) DeviceObject->DeviceExtension;
if( pcx->flags & NGPSUSB_ISPDO )
{
NTSTATUS status;
switch( stack->MinorFunction )
{
case IRP_MN_REMOVE_DEVICE:
Irp->IoStatus.Status = STATUS_SUCCESS;
IoCompleteRequest ( Irp, IO_NO_INCREMENT );
status = STATUS_SUCCESS;
break;
}
return status;
}

This is a driver that has been in development and in use in the field for many years. We’ve only recently decided to get WHQL logo. Unfortunately, the previous maintainer of the driver quit recently and I got tasked with doing the WHQL work.

I’ll trust your judgment about the bus driver PDO being deleted nonetheless. Maybe it’s getting deleted by another code path that has no tracing.

Put a breakpoint on IoDeleteDevice and see who is calling it by looking at the stack

d

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@hotmail.com
Sent: Tuesday, December 16, 2008 1:38 PM
To: Windows System Software Devs Interest List
Subject: RE:[ntdev] IRP_MN_REMOVE_DEVICE and bus relations

Yes, I’m pretty sure of it. The whole code, unrolled would look like this (cut n paste):

PCOMMON_EXTENSION pcx = (PCOMMON_EXTENSION) DeviceObject->DeviceExtension;
if( pcx->flags & NGPSUSB_ISPDO )
{
NTSTATUS status;
switch( stack->MinorFunction )
{
case IRP_MN_REMOVE_DEVICE:
Irp->IoStatus.Status = STATUS_SUCCESS;
IoCompleteRequest ( Irp, IO_NO_INCREMENT );
status = STATUS_SUCCESS;
break;
}
return status;
}

This is a driver that has been in development and in use in the field for many years. We’ve only recently decided to get WHQL logo. Unfortunately, the previous maintainer of the driver quit recently and I got tasked with doing the WHQL work.

I’ll trust your judgment about the bus driver PDO being deleted nonetheless. Maybe it’s getting deleted by another code path that has no tracing.


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

Thanks for the suggestion. Tried it and nobody called IoDeleteDevice! Here’s the trace with the breakpoint set:

OurUsb - fdo 0x896F0138 - To STOPPED from PENDINGSTOP
PNPFILTR: Time taken for IRP_MN_STOP_DEVICE to get processed for the PDO 89C3FC88 is 15 miliseconds
PNPFILTR: Completing FilterStop with status 0x4 for stack with PDO 0x89c3fc88
PNPFILTR: Received IRP_MN_START_DEVICE for stack with PDO 0x89C3FC88
OurUsb - fdo 0x896F0138 - PNP Request (IRP_MN_START_DEVICE)
OurUsb - fdo 0x896F0138 - To WORKING from STOPPED
PNPFILTR: Time taken for IRP_MN_START_DEVICE to get processed for the PDO 89C3FC88 is 250 miliseconds
PNPFILTR: Start: Test Event cleared
PNPFILTR: Irp recorded, sequence count = 1
PNPFILTR: Completing Start request with status == 0x00000002 PDO = 0x89C3FC88
PNPFILTR: Received IRP_MN_START_DEVICE for stack with PDO 0x896C8BE8
OurSer - fdo 0x89B61030 - PNP Request ( IRP_MN_START_DEVICE -> HandleStartDevice )
OurUsb - pdo 0x896C8BE8 - PNP Request( IRP_MN_START_DEVICE)
OurUsb - pdo 0x896C8BE8 - Internal Control Request
OurSer - FDO 0x89B61030 - hInpipe 0x89bac024
OurSer - FDO 0x89B61030 - hOutpipe 0x89bac044
OurSer - FDO 0x89B61030 - MaximumTransferSize 4096 0x1000
OurSer - FDO 0x89B61030 - MaxPacketSize 64 0x40
OurSer - Retriving Queue size from : \REGISTRY\MACHINE\SYSTEM\ControlSet004\Services\NGPSSER
OurSer - fdo 0x89B61030 - EnableAllInterfaces: enable (1)
OurSer - fdo 0x89B61030 - To WORKING from STOPPED
PNPFILTR: Time taken for IRP_MN_START_DEVICE to get processed for the PDO 896C8BE8 is 15 miliseconds
PNPFILTR: Completing Start request with status == 0x00000001 PDO = 0x896C8BE8
PNPFILTR: Received IRP_MN_START_DEVICE for stack with PDO 0x89794F00
OurSer - fdo 0x89D84030 - PNP Request ( IRP_MN_START_DEVICE -> HandleStartDevice )
OurUsb - pdo 0x89794F00 - PNP Request( IRP_MN_START_DEVICE)
OurUsb - pdo 0x89794F00 - Internal Control Request
OurSer - FDO 0x89D84030 - hInpipe 0x89bac064
OurSer - FDO 0x89D84030 - hOutpipe 0x89bac084
OurSer - FDO 0x89D84030 - MaximumTransferSize 4096 0x1000
OurSer - FDO 0x89D84030 - MaxPacketSize 64 0x40
OurSer - Retriving Queue size from : \REGISTRY\MACHINE\SYSTEM\ControlSet004\Services\NGPSSER
OurSer - fdo 0x89D84030 - EnableAllInterfaces: enable (1)
OurSer - fdo 0x89D84030 - To WORKING from STOPPED
PNPFILTR: Time taken for IRP_MN_START_DEVICE to get processed for the PDO 89794F00 is 15 miliseconds
PNPFILTR: Completing Start request with status == 0x00000001 PDO = 0x89794F00
PNPFILTR: Received IRP_MN_START_DEVICE for stack with PDO 0x89B6CD60
OurSer - fdo 0x89B4DB00 - PNP Request ( IRP_MN_START_DEVICE -> HandleStartDevice )
OurUsb - pdo 0x89B6CD60 - PNP Request( IRP_MN_START_DEVICE)
OurUsb - pdo 0x89B6CD60 - Internal Control Request
OurSer - FDO 0x89B4DB00 - hInpipe 0x89bac0a4
OurSer - FDO 0x89B4DB00 - hOutpipe 0x89bac0c4
OurSer - FDO 0x89B4DB00 - MaximumTransferSize 4096 0x1000
OurSer - FDO 0x89B4DB00 - MaxPacketSize 64 0x40
OurSer - Retriving Queue size from : \REGISTRY\MACHINE\SYSTEM\ControlSet004\Services\NGPSSER
OurSer - fdo 0x89B4DB00 - EnableAllInterfaces: enable (1)
OurSer - fdo 0x89B4DB00 - To WORKING from STOPPED
PNPFILTR: Time taken for IRP_MN_START_DEVICE to get processed for the PDO 89B6CD60 is 0 miliseconds
PNPFILTR: Completing Start request with status == 0x00000001 PDO = 0x89B6CD60
Relevant Sequence of Irps:
IRP_MN_QUERY_PNP_DEVICE_STATE
CDisplayGatherer::XmlData: Calling Get XML Data
CDisplayGatherer::XmlData: DisplayGetData(ex) succeeded
PNPFILTR: Received IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
OurSer - fdo 0x89B61030 - PNP Request ( IRP_MN_QUERY_DEVICE_RELATIONS -> DefaultPnpHandler )
OurUsb - pdo 0x896C8BE8 - PNP Request( IRP_MN_QUERY_DEVICE_RELATIONS)
OurUsb - pdo 0x896C8BE8 - PdoHandleQueryRelations
PNPFILTR: Received IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
OurSer - fdo 0x89D84030 - PNP Request ( IRP_MN_QUERY_DEVICE_RELATIONS -> DefaultPnpHandler )
OurUsb - pdo 0x89794F00 - PNP Request( IRP_MN_QUERY_DEVICE_RELATIONS)
OurUsb - pdo 0x89794F00 - PdoHandleQueryRelations
PNPFILTR: Received IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
OurSer - fdo 0x89B4DB00 - PNP Request ( IRP_MN_QUERY_DEVICE_RELATIONS -> DefaultPnpHandler )
OurUsb - pdo 0x89B6CD60 - PNP Request( IRP_MN_QUERY_DEVICE_RELATIONS)
OurUsb - pdo 0x89B6CD60 - PdoHandleQueryRelations
PNPFILTR: Received IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
OurUsb - fdo 0x896F0138 - PNP Request (IRP_MN_QUERY_DEVICE_RELATIONS)
OurUsb - fdo 0x896F0138 - HandleQueryDeviceRelations
OurUsb - fdo 0x896F0138 - DEVICE_RELATION_TYPE : RemovalRelations
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89B6CD60
OurSer - fdo 0x89B4DB00 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89B6CD60 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89B6CD60
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89794F00
OurSer - fdo 0x89D84030 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x89794F00 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x89794F00
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x896C8BE8
OurSer - fdo 0x89B61030 - PNP Request ( IRP_MN_QUERY_REMOVE_DEVICE -> HandleQueryRemove )
OurUsb - pdo 0x896C8BE8 - PNP Request( IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000002 for stack with PDO 0x896C8BE8
PNPFILTR: Received IRP_MN_QUERY_REMOVE_DEVICE for stack with PDO 0x89C3FC88
OurUsb - fdo 0x896F0138 - PNP Request (IRP_MN_QUERY_REMOVE_DEVICE)
PNPFILTR: FilterQueryRemove returning 0x00000004 for stack with PDO 0x89C3FC88
PNPFILTR: Received IRP_MN_REMOVE_DEVICE for stack with PDO 0x89B6CD60
OurSer - fdo 0x89B4DB00 - PNP Request ( IRP_MN_REMOVE_DEVICE -> HandleRemoveDevice )
OurSer - fdo 0x89b4db00 - Disabling device interface
OurSer - fdo 0x89B4DB00 - To REMOVED from PENDINGREMOVE
OurUsb - pdo 0x89B6CD60 - PNP Request( IRP_MN_REMOVE_DEVICE)

***********************************************************************
* THIS VALIDATION BUG IS FATAL AND WILL CAUSE THE VERIFIER TO HALT *
* WINDOWS (BUGCHECK) WHEN THE MACHINE IS NOT UNDER A KERNEL DEBUGGER! *
***********************************************************************

WDM DRIVER ERROR: [ourusb.sys @ 0xBAADF7B0] An IRP dispatch handler for a
PDO has deleted it’s device object, but the hardware has
not been reported as missing in a bus relations query.
DeviceObject = 89B6CD60 - Dispatch = BAADF7B0 - Irp =
8B0B4F20
IRP_MJ_PNP.IRP_MN_REMOVE_DEVICE -

I think it shows that during the relevant test, IoDeleteDevice() is not being called. How does the PnP driver test detects that the device has been deleted? Maybe it is checking something like the refcount and we are somehow mishandling it?

For reference, here’s the command I use to set the breakpoint: bp 804f18d4 “dd @ebp - 0x10 L1”. The address was found by setting a breakpoint on a call to IoDeleteDevice() and tracing in the NT assembler. For some reason, bm nt!IoDeleteDevice didn’t work, so I had to resort to that technique. The command was intended to print the PDO, but it is incorrect. I used the raw argument of the stack view instead to see which PDO was being deleted. (But no call at all occured during the test, so this is irrelevant.)

Any further suggestion appreciated.

For information, the device object being reported as deleted does indeed have a refocunt of zero. Is this normal? Here’s the windbg output (different run, so the address is not teh same as in my previous msg):

kd> dt nt!_DEVICE_OBJECT 0x896c8be8
+0x000 Type : 3
+0x002 Size : 0xd0
+0x004 ReferenceCount : 0
+0x008 DriverObject : 0x896f9ba0 _DRIVER_OBJECT
+0x00c NextDevice : 0x896f0138 _DEVICE_OBJECT
+0x010 AttachedDevice : 0x89b61030 _DEVICE_OBJECT
+0x014 CurrentIrp : (null)
+0x018 Timer : (null)
+0x01c Flags : 0x1040
+0x020 Characteristics : 0x180
+0x024 Vpb : (null)
+0x028 DeviceExtension : 0x896c8ca0
+0x02c DeviceType : 0x22
+0x030 StackSize : 1 ‘’
+0x034 Queue : __unnamed
+0x05c AlignmentRequirement : 0
+0x060 DeviceQueue : _KDEVICE_QUEUE
+0x074 Dpc : _KDPC
+0x094 ActiveThreadCount : 0
+0x098 SecurityDescriptor : 0xe19fb158
+0x09c DeviceLock : _KEVENT
+0x0ac SectorSize : 0
+0x0ae Spare1 : 1
+0x0b0 DeviceObjectExtension : 0x896c8cb8 _DEVOBJ_EXTENSION
+0x0b4 Reserved : (null)