HELP!!! system crash in USB multi stage Bulk out using IOCTLs

[M Taha Masood]

Hello all,


I am using my driver sample from Win2k DDK isousb sample driver , and
wanted to add support in it
for Bulk OUT . So i added an IOCTL for Bulk Transfer . This also
worked fine , however for a limited buffer
size . So i decided to add mutli-staging to it( IRP reuse ) , and for
that basically used the sample code in Bulkusb.sys XP DDK sample .
BulkUsb.sys was handling Bulk write requests through IRP_MJ_WRITE
dispatch routine , but i am doint it through
IOCTLs.
This however crashes my system , and i am at a loss to understand why.
When i single step through the completion routine in the Kernel
debugger , by setting a breakpoint
in the completion routine , and when it hits the breakpoint second
time , sometimes single steppign thru the code
and taking function call stack trace , a call to NT!IoCancelIRP is
showing up , looks like somebody is canceling the
IRP
At other times when not single stepping but with KD attached , it
breaks with a second chance AV in the
IoBuildPartialMdl() function call in completion routine
If KD is not attached , the system crashes and the bugcheck code is
something like MULTIPLE_COMPLETION_ROUTINES ( i fogot
the exact code but u get the idea )

Some of the code snippets from IOctlDispatcher , Bulk_Write_Handler
and CompletionRoutine are as follows:

The EXACT source ( lengthy ) to these functions is also at the very
end of the message .

I would very much appreciate any help
thanks in advance
Taha




IN DEVIOCTL DISPATCH ROUTINE
===============================


..........

case BULK_WRITE:

ntStatus = Bulk_Write_Multiple_Stage(FdoDeviceObject , Irp);

break;


........


Irp->IoStatus.Status = ntStatus;


IoCompleteRequest (Irp,
IO_NO_INCREMENT
);


return ntStatus;



IN BULK_WRITE_MULTIPLE_STAGE
=============================


if(totalLength > MAX_BULK_TRANSFER_SIZE)
{
stageLength = MAX_BULK_TRANSFER_SIZE;
}
else
{
stageLength = totalLength;
}

mdl = IoAllocateMdl((PVOID) virtualAddress,
totalLength,
FALSE,
FALSE,
NULL);


//
// map the portion of user-buffer described by an mdl to another
mdl
//
IoBuildPartialMdl(Irp->MdlAddress,
mdl,
(PVOID) virtualAddress,
stageLength);

urb = ExAllocatePool(NonPagedPool,
sizeof(struct
_URB_BULK_OR_INTERRUPT_TRANSFER));



UsbBuildInterruptOrBulkTransferRequest(
urb,
sizeof(struct
_URB_BULK_OR_INTERRUPT_TRANSFER),
bulkPipeInfo->PipeHandle,
NULL,
mdl,
stageLength,
urbFlags,
NULL);

//
// set BULKUSB_RW_CONTEXT parameters.
//

rwContext->Urb = urb;
rwContext->Mdl = mdl;
rwContext->Length = totalLength - stageLength;
rwContext->Numxfer = 0;
rwContext->VirtualAddress = virtualAddress + stageLength;
rwContext->DeviceExtension = deviceExtension;

//
// use the original read/write irp as an internal device control
irp
//

nextStack = IoGetNextIrpStackLocation(Irp);
nextStack->MajorFunction = IRP_MJ_INTERNAL_DEVICE_CONTROL;
nextStack->Parameters.Others.Argument1 = (PVOID) urb;
nextStack->Parameters.DeviceIoControl.IoControlCode =

IOCTL_INTERNAL_USB_SUBMIT_URB;

IoSetCompletionRoutine(Irp,

(PIO_COMPLETION_ROUTINE)ReadWriteCompletion,
rwContext,
TRUE,
TRUE,
TRUE);


IoMarkIrpPending(Irp);


ntStatus = IoCallDriver(deviceExtension->TopOfStackDeviceObject,
Irp);

return STATUS_PENDING;

IN CASE OF ERRORS , we jump to a label which has the following (
completes IRP )
--------------------------------------------------------------------------------

Irp->IoStatus.Status = ntStatus;
Irp->IoStatus.Information = 0;
IoCompleteRequest(Irp, IO_NO_INCREMENT);
return ntStatus;


IN THE COMPLETION ROUTINE
==========================

ntStatus = Irp->IoStatus.Status;

( PSEUDOCODE ) ...if ntStatus == Success , then handle chunk , and
return STATUS_MORE_PROCESSING_REQUIRED;

else for last chunk keep going and return whatever ntStatus has





========================
************************
EXACT SOURCE
***********************
=======================



#define IOCTL_USBXGA_BULK_WRITE CTL_CODE(FILE_DEVICE_UNKNOWN, \

USBXGA_IOCTL_INDEX+9,\
METHOD_IN_DIRECT,
\
FILE_ANY_ACCESS)

typedef struct _BULKUSB_RW_CONTEXT {

PURB Urb;
PMDL Mdl;
ULONG Length; // remaining to xfer
ULONG Numxfer; // cumulate xfer
ULONG_PTR VirtualAddress; // va for next segment of xfer.
PDEVICE_EXTENSION DeviceExtension;

} BULKUSB_RW_CONTEXT, * PBULKUSB_RW_CONTEXT;


///////////////////////////////////////////////////////////////////////////////////////////////////
///////////////////////////////////////////////////////////////////////////////////////////////////
NTSTATUS USBXGA_ProcessIOCTL(IN PDEVICE_OBJECT FdoDeviceObject, IN
PIRP Irp)
{

PIO_STACK_LOCATION irpStack;
PVOID ioBuffer;
ULONG inputBufferLength;
ULONG outputBufferLength;
PDEVICE_EXTENSION deviceExtension;
ULONG ioControlCode;
NTSTATUS ntStatus;
UCHAR RefreshRate, Resolution;

USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...Start\n"));

USBXGA_KdPrint( DBGLVL_DEFAULT,("IRP_MJ_DEVICE_CONTROL\n"));

USBXGA_IncrementIoCount(FdoDeviceObject);

//
// Get a pointer to the current location in the Irp. This is where
// the function codes and parameters are located.
//

deviceExtension = FdoDeviceObject->DeviceExtension;


// Can't accept a new io request if:
// 1) device is removed,
// 2) has never been started,
// 3) is stopped,
// 4) has a remove request pending,
// 5) has a stop device pending
if ( !USBXGA_CanAcceptIoRequests( FdoDeviceObject ) )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...USBXGA_CanAcceptIoRequests
Fail\n"));
ntStatus = STATUS_DELETE_PENDING;
Irp->IoStatus.Status = ntStatus;
Irp->IoStatus.Information = 0;

IoCompleteRequest( Irp, IO_NO_INCREMENT );

USBXGA_DecrementIoCount(FdoDeviceObject);
return ntStatus;
}

irpStack = IoGetCurrentIrpStackLocation (Irp);

Irp->IoStatus.Status = STATUS_SUCCESS;
Irp->IoStatus.Information = 0;

// get pointers and lengths of the caller's (user's) IO buffer
ioBuffer = Irp->AssociatedIrp.SystemBuffer;
inputBufferLength =
irpStack->Parameters.DeviceIoControl.InputBufferLength;
outputBufferLength =
irpStack->Parameters.DeviceIoControl.OutputBufferLength;

ioControlCode = irpStack->Parameters.DeviceIoControl.IoControlCode;
USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...ioControlCode=%x\n",ioControlCode));

switch (ioControlCode)
{
case IOCTL_USBXGA_BULK_WRITE:
USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...IOCTL_USBXGA_BULK_WRITE\n"));
ntStatus = USBXGA_Bulk_Write_Multiple_Stage(FdoDeviceObject , Irp);

break;
default:
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...Unhandled\n"));

ntStatus =
Irp->IoStatus.Status = STATUS_INVALID_PARAMETER;
}
}

Irp->IoStatus.Status = ntStatus;


IoCompleteRequest (Irp,
IO_NO_INCREMENT
);

USBXGA_DecrementIoCount(FdoDeviceObject);
USBXGA_KdPrint( DBGLVL_DEFAULT,("USBXGA_ProcessIOCTL...End\n"));

return ntStatus;
}



///////////////////////////////////////////////////////////////////////////////////////////////////
///////////////////////////////////////////////////////////////////////////////////////////////////

NTSTATUS
USBXGA_Bulk_Write_Multiple_Stage(
IN PDEVICE_OBJECT fdo,
IN PIRP Irp
)
/*++
Routine Description:

Arguments:

Return Value:
NT status code
STATUS_SUCCESS: Read was done successfully


--*/
{
PMDL mdl = NULL;
PURB urb = NULL;
ULONG totalLength;
ULONG stageLength;
ULONG urbFlags;
BOOLEAN read;
NTSTATUS ntStatus;
ULONG_PTR virtualAddress;
PFILE_OBJECT fileObject = NULL;
PDEVICE_EXTENSION deviceExtension= NULL;
PIO_STACK_LOCATION irpStack = NULL;
PIO_STACK_LOCATION nextStack = NULL;
PBULKUSB_RW_CONTEXT rwContext = NULL;
PUSBD_PIPE_INFORMATION bulkPipeInfo = NULL;
PUSBD_INTERFACE_INFORMATION interfaceInfo = NULL;
BOOLEAN bFoundBulkPipe = FALSE;
UINT32 nCurrPipe;

//
// initialize variables
//
urb = NULL;
mdl = NULL;
rwContext = NULL;
totalLength = 0;
irpStack = IoGetCurrentIrpStackLocation(Irp);
fileObject = irpStack->FileObject;
read = (irpStack->MajorFunction == IRP_MJ_READ) ? TRUE : FALSE;
deviceExtension = (PDEVICE_EXTENSION) fdo->DeviceExtension;

USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() Begins..\n"));


if(TRUE != deviceExtension->DeviceStarted )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ...ERROR!Invalid device state ...
Exiting \n"));
ntStatus = STATUS_INVALID_DEVICE_STATE;
goto BulkUsb_DispatchReadWrite_Exit;
}

interfaceInfo = NULL;
interfaceInfo = deviceExtension->UsbInterface;

if (!interfaceInfo)
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ERROR! no interface info -
Exiting"));
ntStatus = STATUS_UNSUCCESSFUL;
goto BulkUsb_DispatchReadWrite_Exit;
}

for ( nCurrPipe=0 ; nCurrPipe < interfaceInfo->NumberOfPipes ;
nCurrPipe++)
{
if ( UsbdPipeTypeBulk == interfaceInfo->Pipes[nCurrPipe].PipeType )
{
bFoundBulkPipe = TRUE;
break;
}
}

if ( FALSE == bFoundBulkPipe )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ERROR! , did not find a Bulk Pipe
in the interface - Exiting"));
ntStatus = STATUS_INVALID_PARAMETER;
goto BulkUsb_DispatchReadWrite_Exit;
}

bulkPipeInfo = &(interfaceInfo->Pipes[nCurrPipe] );

rwContext = (PBULKUSB_RW_CONTEXT)
ExAllocatePool(NonPagedPool,
sizeof(BULKUSB_RW_CONTEXT));

if(NULL == rwContext )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ...ERROR! Failed to alloc mem for
rwContext.. Exiting \n"));
ntStatus = STATUS_INSUFFICIENT_RESOURCES;
goto BulkUsb_DispatchReadWrite_Exit;
}

if(Irp->MdlAddress)
{
totalLength = MmGetMdlByteCount(Irp->MdlAddress);
}
else
{
//just log to the debugger that we got a NULL MDL Address
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : Irp->MdlAddress is
NULL \n"));
}

if(totalLength > USBXGA_ARBITRARY_MAX_BULK_BUFFER_SIZE )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ...ERROR! total buffer length is
GREATER than Arbitrary total size.. Exiting \n"));
ntStatus = STATUS_INVALID_PARAMETER;
ExFreePool(rwContext);
goto BulkUsb_DispatchReadWrite_Exit;
}

if(totalLength == 0)
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : Transfer data
length = 0\n"));
ntStatus = STATUS_SUCCESS;
ExFreePool(rwContext);
goto BulkUsb_DispatchReadWrite_Exit;
}

urbFlags = USBD_SHORT_TRANSFER_OK;
virtualAddress = (ULONG_PTR)
MmGetMdlVirtualAddress(Irp->MdlAddress);

if(read)
{
urbFlags |= USBD_TRANSFER_DIRECTION_IN;
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : Read operation on
Bulk pipe \n"));
}
else
{
urbFlags |= USBD_TRANSFER_DIRECTION_OUT;
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : Write operation on
Bulk pipe \n"));
}

//
// the transfer request is for totalLength.
// we can perform a max of ISO_MAX_BULK_TRANSFER_SIZE
// in each stage.
//


if(totalLength > ISO_MAX_BULK_TRANSFER_SIZE)
{
stageLength = ISO_MAX_BULK_TRANSFER_SIZE;
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : stageLength =
ISO_MAX_BULK_TRANSFER_SIZE \n"));
}
else
{
stageLength = totalLength;
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info Only : stageLength =
totalLength \n"));
}

mdl = IoAllocateMdl((PVOID) virtualAddress,
totalLength,
FALSE,
FALSE,
NULL);

if(NULL == mdl )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... ERROR! Failed to alloc mem for
mdl .. Exiting \n"));
ntStatus = STATUS_INSUFFICIENT_RESOURCES;
ExFreePool(rwContext);
goto BulkUsb_DispatchReadWrite_Exit;
}

//
// map the portion of user-buffer described by an mdl to another
mdl
//
IoBuildPartialMdl(Irp->MdlAddress,
mdl,
(PVOID) virtualAddress,
stageLength);

urb = ExAllocatePool(NonPagedPool,
sizeof(struct
_URB_BULK_OR_INTERRUPT_TRANSFER));

if(NULL == urb )
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... ERROR! Failed to alloc mem for
urb.. Exiting \n"));
ntStatus = STATUS_INSUFFICIENT_RESOURCES;
ExFreePool(rwContext);
IoFreeMdl(mdl);
goto BulkUsb_DispatchReadWrite_Exit;
}

UsbBuildInterruptOrBulkTransferRequest(
urb,
sizeof(struct
_URB_BULK_OR_INTERRUPT_TRANSFER),
bulkPipeInfo->PipeHandle,
NULL,
mdl,
stageLength,
urbFlags,
NULL);

//
// set BULKUSB_RW_CONTEXT parameters.
//

rwContext->Urb = urb;
rwContext->Mdl = mdl;
rwContext->Length = totalLength - stageLength;
rwContext->Numxfer = 0;
rwContext->VirtualAddress = virtualAddress + stageLength;
rwContext->DeviceExtension = deviceExtension;

//
// use the original read/write irp as an internal device control
irp
//

nextStack = IoGetNextIrpStackLocation(Irp);
nextStack->MajorFunction = IRP_MJ_INTERNAL_DEVICE_CONTROL;
nextStack->Parameters.Others.Argument1 = (PVOID) urb;
nextStack->Parameters.DeviceIoControl.IoControlCode =

IOCTL_INTERNAL_USB_SUBMIT_URB;

IoSetCompletionRoutine(Irp,

(PIO_COMPLETION_ROUTINE)USBXGA_BulkUsb_ReadWriteCompletion,
rwContext,
TRUE,
TRUE,
TRUE);

//
// since we return STATUS_PENDING call IoMarkIrpPending.
// This is the boiler plate code.
// This may cause extra overhead of an APC for the Irp completion
// but this is the correct thing to do.
//

IoMarkIrpPending(Irp);


USBXGA_IncrementIoCount(fdo);

USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... Info only: About to Call
IoCallDriver \n"));
ntStatus = IoCallDriver(deviceExtension->TopOfStackDeviceObject,
Irp);

if(!NT_SUCCESS(ntStatus))
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n IoCallDriver fails with status
%X\n", ntStatus));
//
// if the device was yanked out, then the pipeInformation
// field is invalid.
// similarly if the request was cancelled, then we need not
// invoked reset pipe/device.
//
if( (ntStatus != STATUS_CANCELLED) &&
(ntStatus != STATUS_DEVICE_NOT_CONNECTED)
)
{

ntStatus = USBXGA_ResetPipe(fdo, bulkPipeInfo);
if(!NT_SUCCESS(ntStatus))
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... ERROR! USBXGA_ResetPipe failed
with ntstatus == %x , Attempting to Reset Device\n" , ntStatus));
}
}
else
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_Bulk_Write_Multiple_Stage() ... ntStatus is STATUS_CANCELLED or
STATUS_DEVICE_NOT_CONNECTED\n"));
}
}

//
// we return STATUS_PENDING and not the status returned by the
lower layer.
//
return STATUS_PENDING;

BulkUsb_DispatchReadWrite_Exit:

Irp->IoStatus.Status = ntStatus;
Irp->IoStatus.Information = 0;

IoCompleteRequest(Irp, IO_NO_INCREMENT);
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n BulkUsb_DispatchReadWrite -
ends\n"));


return ntStatus;
}



///////////////////////////////////////////////////////////////////////////////////////////////////
///////////////////////////////////////////////////////////////////////////////////////////////////


NTSTATUS
USBXGA_BulkUsb_ReadWriteCompletion(
IN PDEVICE_OBJECT DeviceObject,
IN PIRP Irp,
IN PVOID Context
)

{
ULONG stageLength;
NTSTATUS ntStatus;
PIO_STACK_LOCATION nextStack;
PBULKUSB_RW_CONTEXT rwContext;

//
// initialize variables
//
rwContext = (PBULKUSB_RW_CONTEXT) Context;
ntStatus = Irp->IoStatus.Status;

UNREFERENCED_PARAMETER(DeviceObject);
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_BulkUsb_ReadWriteCompletion() Begins..\n"));

//
// successfully performed a stageLength of transfer.
// check if we need to recirculate the irp.
//
if(NT_SUCCESS(ntStatus)) {

if(rwContext) {

rwContext->Numxfer +=
rwContext->Urb->UrbBulkOrInterruptTransfer.TransferBufferLength;

if(rwContext->Length) {

//
// another stage transfer
//
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_BulkUsb_ReadWriteCompletion() ...Another stage transfer...
...\n"));

if(rwContext->Length > ISO_MAX_BULK_TRANSFER_SIZE) {

stageLength = ISO_MAX_BULK_TRANSFER_SIZE;
}
else {

stageLength = rwContext->Length;
}

IoBuildPartialMdl(Irp->MdlAddress,
rwContext->Mdl,
(PVOID) rwContext->VirtualAddress,
stageLength);

//
// reinitialize the urb
//
rwContext->Urb->UrbBulkOrInterruptTransfer.TransferBufferLength
=
stageLength;
rwContext->VirtualAddress += stageLength;
rwContext->Length -= stageLength;

nextStack = IoGetNextIrpStackLocation(Irp);
nextStack->MajorFunction =
IRP_MJ_INTERNAL_DEVICE_CONTROL;
nextStack->Parameters.Others.Argument1 =
rwContext->Urb;
nextStack->Parameters.DeviceIoControl.IoControlCode =

IOCTL_INTERNAL_USB_SUBMIT_URB;

IoSetCompletionRoutine(Irp,

USBXGA_BulkUsb_ReadWriteCompletion,
rwContext,
TRUE,
TRUE,
TRUE);

IoCallDriver(rwContext->DeviceExtension->TopOfStackDeviceObject,
Irp);

return STATUS_MORE_PROCESSING_REQUIRED;
}
else {

//
// this is the last transfer
//

Irp->IoStatus.Information = rwContext->Numxfer;
}
}
}
else
{
USBXGA_KdPrint( DBGLVL_DEFAULT,("\n
USBXGA_BulkUsb_ReadWriteCompletion - failed with ntStatus = %X\n",
ntStatus));
}

if(rwContext)
{
//
// dump rwContext
//

USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->Urb =
%X\n",
rwContext->Urb));
USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->Mdl =
%X\n",
rwContext->Mdl));
USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->Length =
%d\n",
rwContext->Length));
USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->Numxfer =
%d\n",
rwContext->Numxfer));
USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->VirtualAddress =
%X\n",
rwContext->VirtualAddress));
USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - rwContext->DeviceExtension =
%X\n",
rwContext->DeviceExtension));

USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() -
BulkUsb_ReadWriteCompletion::"));

USBXGA_DecrementIoCount(DeviceObject);


ExFreePool(rwContext->Urb);
IoFreeMdl(rwContext->Mdl);
ExFreePool(rwContext);
}

USBXGA_KdPrint(DBGLVL_DEFAULT,
("USBXGA_BulkUsb_ReadWriteCompletion() - ends\n"));

return ntStatus;
}