USB to virtual serial port driver crashes with MULTIPLE_IRP_COMPLETE_REQUESTS (44)

NTDEV
1

Hi,
I have a dual driver(bus driver and function driver) that multiplexes a USB GPS device to 3 virtual serial ports
There is a crash with following error on some specific targets(Win7 tablet PCs with 32bit).
And it works perfectly fine on all other machines for more than a week continuously including Win7 32bit normal PCs.
Can you give me any hints why this is failing?

MULTIPLE_IRP_COMPLETE_REQUESTS (44)
A driver has requested that an IRP be completed (IoCompleteRequest()), but
the packet has already been completed. This is a tough bug to find because
the easiest case, a driver actually attempted to complete its own packet
twice, is generally not what happened. Rather, two separate drivers each
believe that they own the packet, and each attempts to complete it. The
first actually works, and the second fails. Tracking down which drivers
in the system actually did this is difficult, generally because the trails
of the first driver have been covered by the second. However, the driver
stack for the current request can be found by examining the DeviceObject
fields in each of the stack locations.
Arguments:
Arg1: 84b87308, Address of the IRP
Arg2: 00000eae
Arg3: 00000000
Arg4: 00000000

FAULTING_SOURCE_CODE:
1039: {
1040: Irp->IoStatus.Status = status;
1041: IoSetCancelRoutine(Irp, NULL);
1042: IoCompleteRequest( Irp, IO_NO_INCREMENT );

1043: return status;
1044: }
1045:
1046:
1047: ///////////////////////////////////////////////////////////////////////////////
1048:

here
xxxxser is a function driver
xxxxusb is a bus driver
overall its a usb to 3 virtual ports driver for a bulk transfer GPS device

WARNING: Stack unwind information not available. Following frames may be wrong.
8c276a28 a9b1aa97 8c276a40 a9b1aa5b 84b87308 nt!RtlCaptureContext+0x629
8c276a30 a9b1aa5b 84b87308 00000000 8c276ac8 xxxxser!CompleteRequest+0x27 //CompleteRequest2() that calls IoCompleteRequest( Irp, IO_NO_INCREMENT );
8c276a40 a9b2129d 84b87308 00000000 00000050 xxxxser!CompleteRequest+0x1b //CompleteRequest() that calls CompleteRequest2()
8c276ac8 a9b22df3 859eb0e8 85ed5720 875fe7f0 xxxxser!CompleteReadIrp+0x42d //CompleteReadIrp() that calls CompleteRequest() and then StartNextPacket()
8c276b34 82096dd3 859eb030 87bdbcf0 859eb1e4 xxxxser!OnCompleteUsbReaderIrp+0x513 //OnCompleteUsbReaderIrp that calls CompleteReadIrp() and returns STATUS_MORE_PROCESSING_REQUIRED
8c276b78 a9b046c1 00000204 89bf763c 87bdbcf0 nt!RtlCaptureContext+0x29f
8c276b8c 82096dd3 877b6410 89bf74d0 00000000 xxxxusb!PdoOnRepeaterComplete+0x81 //bus driver : PdoOnRepeaterComplete() that calls IoCompleteRequest and returns STATUS_MORE_PROCESSING_REQUIRED
8c276bd0 90a3d30d 82059788 84bc38f0 00000000 nt!RtlCaptureContext+0x29f
8c276c00 90a3df55 87bcbb28 89bf74d0 859eb1e4 USBPORT+0x430d
8c276c2c 90a3e6f6 85ed5028 85ed50f0 85ed5a98 USBPORT+0x4f55
8c276c54 90a3a9ce 85ed5028 85ed5a98 85ed5002 USBPORT+0x56f6
8c276c78 82096675 85ed5aa4 85ed5002 00000000 USBPORT+0x19ce
8c276cd4 820964d8 8c25a120 8c25f800 00000000 nt!KiDispatchInterrupt+0xa05
8c276d20 820962f8 00000000 0000000e 318bfc81 nt!KiDispatchInterrupt+0x868
8c276d24 00000000 0000000e 318bfc81 48823489 nt!KiDispatchInterrupt+0x688

here is the code for respective functions
****************************************************************************************
NTSTATUS PdoOnRepeaterComplete( PDEVICE_OBJECT tdo, PIRP subirp, PVOID pv )// bus driver
{

ObDereferenceObject( tdo );
PIO_STACK_LOCATION substack = IoGetCurrentIrpStackLocation( subirp );
PIRP Irp = (PIRP) substack->Parameters.Others.Argument1;

Irp->IoStatus.Status = subirp->IoStatus.Status;
Irp->IoStatus.Information = subirp->IoStatus.Information;

IoFreeIrp( subirp );

IoCompleteRequest( Irp, IO_NO_INCREMENT );

return STATUS_MORE_PROCESSING_REQUIRED;
}
******************************************************************************************

******************************************************************************************
//function driver
NTSTATUS OnCompleteUsbReaderIrp (PDEVICE_OBJECT pFdo_, PIRP pIrp_, PVOID pContext_)
{

ReportEvent ( pFdo_, Event );

CompleteReadIrp ( pdx );

return STATUS_MORE_PROCESSING_REQUIRED;

}

VOID CompleteReadIrp ( PVOID ctx )
{

// Complete the Irp

IoReleaseRemoveLock ( &pdx->RemoveLock, Irp );
CompleteRequest ( Irp, status, ulBytesRequested );

// Service the next request

KeReleaseSpinLock ( &pdx->dqRead.lock, oldirql );
StartNextPacket ( &pdx->dqRead, pdx->DeviceObject );
}

__drv_maxIRQL( DISPATCH_LEVEL )
__drv_arg( Irp, __in )
__drv_arg( status, __in )
__drv_arg( info, __in )
NTSTATUS CompleteRequest( PIRP Irp, NTSTATUS status, ULONG_PTR info)
{
Irp->IoStatus.Information = info;
return CompleteRequest( Irp, status );
}

__drv_maxIRQL( DISPATCH_LEVEL )
__drv_arg( Irp, __in )
__drv_arg( status, __in )
NTSTATUS CompleteRequest( PIRP Irp, NTSTATUS status )
{
Irp->IoStatus.Status = status;
IoSetCancelRoutine(Irp, NULL);
IoCompleteRequest( Irp, IO_NO_INCREMENT );
return status;
}
*******************************************************************************************

2

xxxxx@gmail.com wrote:

Hi,
I have a dual driver(bus driver and function driver) that multiplexes a USB GPS device to 3 virtual serial ports
There is a crash with following error on some specific targets(Win7 tablet PCs with 32bit).
And it works perfectly fine on all other machines for more than a week continuously including Win7 32bit normal PCs.
Can you give me any hints why this is failing?

You have a lot of IRPs flowing around here – it’s not surprising things
get confused.

So, your function driver receives an IRP from above. It then creates
its own IRP, and submits it to the bus. The bus driver then creates
ANOTHER IRP, and sends that down to USB. Right? Otherwise, your
completion routines don’t make sense. You can’t return
STATUS_MORE_PROCESSING_REQUIRED unless this is an IRP created within
that driver.

Is anyone cleaning up those other IRPs? Do you have any cancel
processing? That’s an easy way to get multiple completions.

You may have to resort to using KdPrint to trace the IRPs by address to
figure out how this is happening.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

3

Turn on Driver Verifier with the IRP Logging option, you can then run
“!verifier 100 address” and get a log of all the IoCompleteRequest calls for
the IRP. It’s potentially much easier to track the problem down this way (or
you might find the bug through another Verifier check).

-scott
OSR
@OSRDrivers

wrote in message news:xxxxx@ntdev…

Hi,
I have a dual driver(bus driver and function driver) that multiplexes a USB
GPS device to 3 virtual serial ports
There is a crash with following error on some specific targets(Win7 tablet
PCs with 32bit).
And it works perfectly fine on all other machines for more than a week
continuously including Win7 32bit normal PCs.
Can you give me any hints why this is failing?

MULTIPLE_IRP_COMPLETE_REQUESTS (44)
A driver has requested that an IRP be completed (IoCompleteRequest()), but
the packet has already been completed. This is a tough bug to find because
the easiest case, a driver actually attempted to complete its own packet
twice, is generally not what happened. Rather, two separate drivers each
believe that they own the packet, and each attempts to complete it. The
first actually works, and the second fails. Tracking down which drivers
in the system actually did this is difficult, generally because the trails
of the first driver have been covered by the second. However, the driver
stack for the current request can be found by examining the DeviceObject
fields in each of the stack locations.
Arguments:
Arg1: 84b87308, Address of the IRP
Arg2: 00000eae
Arg3: 00000000
Arg4: 00000000

FAULTING_SOURCE_CODE:
1039: {
1040: Irp->IoStatus.Status = status;
1041: IoSetCancelRoutine(Irp, NULL);
1042: IoCompleteRequest( Irp, IO_NO_INCREMENT );

1043: return status;
1044: }
1045:
1046:
1047:
///////////////////////////////////////////////////////////////////////////////
1048:

here
xxxxser is a function driver
xxxxusb is a bus driver
overall its a usb to 3 virtual ports driver for a bulk transfer GPS device

WARNING: Stack unwind information not available. Following frames may be
wrong.
8c276a28 a9b1aa97 8c276a40 a9b1aa5b 84b87308 nt!RtlCaptureContext+0x629
8c276a30 a9b1aa5b 84b87308 00000000 8c276ac8 xxxxser!CompleteRequest+0x27
//CompleteRequest2() that calls IoCompleteRequest( Irp, IO_NO_INCREMENT );
8c276a40 a9b2129d 84b87308 00000000 00000050 xxxxser!CompleteRequest+0x1b
//CompleteRequest() that calls CompleteRequest2()
8c276ac8 a9b22df3 859eb0e8 85ed5720 875fe7f0 xxxxser!CompleteReadIrp+0x42d
//CompleteReadIrp() that calls CompleteRequest() and then StartNextPacket()
8c276b34 82096dd3 859eb030 87bdbcf0 859eb1e4
xxxxser!OnCompleteUsbReaderIrp+0x513 //OnCompleteUsbReaderIrp that calls
CompleteReadIrp() and returns STATUS_MORE_PROCESSING_REQUIRED
8c276b78 a9b046c1 00000204 89bf763c 87bdbcf0 nt!RtlCaptureContext+0x29f
8c276b8c 82096dd3 877b6410 89bf74d0 00000000
xxxxusb!PdoOnRepeaterComplete+0x81 //bus driver : PdoOnRepeaterComplete()
that calls IoCompleteRequest and returns STATUS_MORE_PROCESSING_REQUIRED
8c276bd0 90a3d30d 82059788 84bc38f0 00000000 nt!RtlCaptureContext+0x29f
8c276c00 90a3df55 87bcbb28 89bf74d0 859eb1e4 USBPORT+0x430d
8c276c2c 90a3e6f6 85ed5028 85ed50f0 85ed5a98 USBPORT+0x4f55
8c276c54 90a3a9ce 85ed5028 85ed5a98 85ed5002 USBPORT+0x56f6
8c276c78 82096675 85ed5aa4 85ed5002 00000000 USBPORT+0x19ce
8c276cd4 820964d8 8c25a120 8c25f800 00000000 nt!KiDispatchInterrupt+0xa05
8c276d20 820962f8 00000000 0000000e 318bfc81 nt!KiDispatchInterrupt+0x868
8c276d24 00000000 0000000e 318bfc81 48823489 nt!KiDispatchInterrupt+0x688

here is the code for respective functions
****************************************************************************************
NTSTATUS PdoOnRepeaterComplete( PDEVICE_OBJECT tdo, PIRP subirp, PVOID
pv )// bus driver
{

ObDereferenceObject( tdo );
PIO_STACK_LOCATION substack = IoGetCurrentIrpStackLocation( subirp );
PIRP Irp = (PIRP) substack->Parameters.Others.Argument1;

Irp->IoStatus.Status = subirp->IoStatus.Status;
Irp->IoStatus.Information = subirp->IoStatus.Information;

IoFreeIrp( subirp );

IoCompleteRequest( Irp, IO_NO_INCREMENT );

return STATUS_MORE_PROCESSING_REQUIRED;
}
******************************************************************************************

******************************************************************************************
//function driver
NTSTATUS OnCompleteUsbReaderIrp (PDEVICE_OBJECT pFdo_, PIRP pIrp_, PVOID
pContext_)
{

ReportEvent ( pFdo_, Event );

CompleteReadIrp ( pdx );

return STATUS_MORE_PROCESSING_REQUIRED;

}

VOID CompleteReadIrp ( PVOID ctx )
{

// Complete the Irp

IoReleaseRemoveLock ( &pdx->RemoveLock, Irp );
CompleteRequest ( Irp, status, ulBytesRequested );

// Service the next request

KeReleaseSpinLock ( &pdx->dqRead.lock, oldirql );
StartNextPacket ( &pdx->dqRead, pdx->DeviceObject );
}

__drv_maxIRQL( DISPATCH_LEVEL )
__drv_arg( Irp, __in )
__drv_arg( status, __in )
__drv_arg( info, __in )
NTSTATUS CompleteRequest( PIRP Irp, NTSTATUS status, ULONG_PTR info)
{
Irp->IoStatus.Information = info;
return CompleteRequest( Irp, status );
}

__drv_maxIRQL( DISPATCH_LEVEL )
__drv_arg( Irp, __in )
__drv_arg( status, __in )
NTSTATUS CompleteRequest( PIRP Irp, NTSTATUS status )
{
Irp->IoStatus.Status = status;
IoSetCancelRoutine(Irp, NULL);
IoCompleteRequest( Irp, IO_NO_INCREMENT );
return status;
}
*******************************************************************************************

4

Hi Sai,

You are trying to Release the LOCK before acquiring the spinlock.

Plz commented out the both line and try

// IoReleaseRemoveLock ( &pdx->RemoveLock, Irp );
// KeReleaseSpinLock ( &pdx->dqRead.lock, oldirql );

If it will work, let me know i will give the reason.

thanks,
Raku