Why system lower driver never finish the IRP sometimes?

NTDEV
1

We developed a driver for a 1394/SBP2 storage device, we send the commands to the device through cdb in srb(the driver is above sbp2port driver). We found a strange problem that the lower driver(sbp2port or 1394bus?) pends certain IRP and never finishes it on vista platform.
In order to detect the media state in the storage device, we need to send a command to the device, we use a timer to send the command to the device periodically.
The process like this:
when received IRP_MN_START_DEVICE,
1 send the request to lower and wait to be finished successfully
2 then initialize the DPC(set the CustomDpc routine) and timer,then set the timer(5 seconds interval)

In the CustomDpc routine, i allocate a workitem and queue it.
In the workitem routine, i did the following:
1 allocate an irp ,
2 initialize it(note:i have set srb.TimeOutValue = 10)
3 set iocompletion routine for the irp
4 call the next lower driver.The code piece like the following:

status = IoCallDriver(fdoExtension->CommonExtension.LowerDeviceObject, irp);

if (status == STATUS_PENDING)
{

DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait IRP to finished \n”);

status = KeWaitForSingleObject(&event, Executive, KernelMode, FALSE,
NULL);//&WaitInterval);

DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait IRP success\n”);

status = ioStatus.Status;
}

Plug and unplug the device many times, in most case, the driver work well(that means at least i can get both the two output as a pair and system not be hung), but sometimes when plug the device in,the IRP was pending, i only got “*********** Wait IRP to finished” output, no “*********** Wait IRP success”(no matter how much time to wait)output. meanwhile, in the device manager, i right click on the device, chose “properties”, the device manager was hang too.
Because i serialize(use a Synchronization Event for this purpose) the command sent to the device,the pending lead other command cann’t be sent to the device later.
I try to find what leads the sbp2port, 1394bus or other lower driver doesn’t complete the irp sometimes, there is no answer, anyone can explain the reason? Any suggestion will be appreciated very much…

2

> 3 set iocompletion routine for the irp

What about your completion routine - you did not show us its code, did you? There is a good chance that the “mystery” is directly related to its code…

Anton Bassov

3

Oh, the completion routine like the following:
{
// Unlock the pages for the data buffer.
if(Irp->MdlAddress) {
MmUnlockPages(Irp->MdlAddress);
IoFreeMdl(Irp->MdlAddress);
} // Signal the caller’s event.
KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);

// Free the IRP.
IoFreeIrp(Irp);

return STATUS_MORE_PROCESSING_REQUIRED;
}

The things that confuses me is that in most times the IRP was completed sucessfully, that me my completion routine was called in most cases, two outputs all can be get in debug view, only sometimes, the IRP was pending, and my completion routine was never been called, and the output for DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait IRP
success\n”) was not received, addtionally,this happens when IRP_MN_START_DEVICE successfully been completed. In my opinion, all the request sent to the device should be returned later, for i have set the timeout value in srb, indeed, this work in most cases, i means for eg, when sending a command to device, i unplug the device ,the request will return at certain time, the time to wait to be returned is the timeout value in the srb.
I don’t think that the IRP was not completed by the lower driver should happen, but it occured.

4

What is Irp->UserEvent??? I have never noticed any mentioning of this field on MSDN, so that, apparently, it is reserved for the system use. Normally if you want a completion routine to signal an event, you just pass it as ‘Context’ parameter to IoSetCompletionRoutine(). I believe what happens here is that you just call KeSetEvent() on the wrong event - the one that you actually wait on never gets signalled, so that your KeWaitForSingleObject() call never returns. Therefore, your code works when IRP gets completed straight away (because you don’t wait ) and fails when it gets completed asynchronously…

Anton Bassov

5

Now, i want to know is that on what kinds of condition the irp may be pended and never be completed by lower driver(sbp2port.sys or 1394bus.sys). So far, i even can not find a way to let the that always happen. About every 20 times plug-and-unplug, i encounter one time that the Irp was pended and never be completed. May be this is a bug of Microsoft, isn’t it? For that really shouldn’t happen at all.

6

anton bassov:
Thanks a lot.
About the event, following may be more clear:

Irp->UserEvent = &event
status = IoCallDriver(fdoExtension->CommonExtension.LowerDeviceObject, irp);

if (status == STATUS_PENDING)
{

DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“***********
Wait IRP to finished \n”);

status = KeWaitForSingleObject(&event, Executive, KernelMode, FALSE,
NULL);//&WaitInterval);

DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait IRP
success\n”);

status = ioStatus.Status;
}

completion routine:

{
// Unlock the pages for the data buffer.
if(Irp->MdlAddress) {
MmUnlockPages(Irp->MdlAddress);
IoFreeMdl(Irp->MdlAddress);
} // Signal the caller’s event.
KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);

// Free the IRP.
IoFreeIrp(Irp);

return STATUS_MORE_PROCESSING_REQUIRED;
}

from the above code, can i say that i set the right event in the completion routine? May be just as you said the member is reserved for system use(that means when i set in the completion routine, followed,the system may changes this member in the irp), so the KeWaitForSingleObject still thought the event wasn’t set?). That is a good ideal, i will try, thanks a lot again.

7

Actually to be robust you should be freeing the entire MDL chain (e.g.
walk the chain, freeing each one) instead of just the first MDL

d

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of activism@163.com
Sent: Tuesday, June 26, 2007 7:10 PM
To: Windows System Software Devs Interest List
Subject: RE:[ntdev] Why system lower driver never finish the IRP
sometimes?

Oh, the completion routine like the following:
{
// Unlock the pages for the data buffer.
if(Irp->MdlAddress) {
MmUnlockPages(Irp->MdlAddress);
IoFreeMdl(Irp->MdlAddress);
} // Signal the caller’s event.
KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);

// Free the IRP.
IoFreeIrp(Irp);

return STATUS_MORE_PROCESSING_REQUIRED;
}

The things that confuses me is that in most times the IRP was completed
sucessfully, that me my completion routine was called in most cases, two
outputs all can be get in debug view, only sometimes, the IRP was
pending, and my completion routine was never been called, and the output
for DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait
IRP
success\n”) was not received, addtionally,this happens when
IRP_MN_START_DEVICE successfully been completed. In my opinion, all the
request sent to the device should be returned later, for i have set the
timeout value in srb, indeed, this work in most cases, i means for eg,
when sending a command to device, i unplug the device ,the request will
return at certain time, the time to wait to be returned is the timeout
value in the srb.
I don’t think that the IRP was not completed by the lower driver should
happen, but it occured.

Questions? First check the Kernel Driver FAQ at
http://www.osronline.com/article.cfm?id=256

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

8

> May be this is a bug of Microsoft, isn’t it?

It is more than likely to be your own bug…

Please show us the code that initializes IRP before passing it down the stack, i.e. everything that you do in between IoAllocateIrp() and IoCallDriver()…

Anton Bassov

9

> Irp->UserEvent = &event
> status = IoCallDriver(fdoExtension->CommonExtension.LowerDeviceObject, irp);

This is *EXACTLY* what I expected to see…

If UserEvent is a reserved field of IRP, the system is free to update it whenever it wishes, although I cannot tell you if, when and why it may want to do so . If it happens, then you just signal the wrong event. Apparently, it happens just once in a while, so that you hang from time to time.

Try to do it the “supported” way, i.e. pass your event as ‘Context’ parameter to IoSetCompletionRoutine(). There is a good chance that everything will start working properly…

Anton Bassov

10

I have test for 30 times plug and unplug, every thing is going well this moment…

11

Thanks , the initializes IRP code like the following:
{
//Srb initialize
Srb.CdbLength = 12;
cdb = (PXDCAM_CDB)Srb.Cdb;
*cdb = *((PXDCAM_CDB)RequestIn);

Srb.SrbFlags = SRB_FLAGS_DATA_OUT | SRB_FLAGS_DATA_IN ;
// Set timeout value from device extension.
Srb.TimeOutValue = 10;
Srb->Length = sizeof(SCSI_REQUEST_BLOCK);

// set Srb fouction.
Srb->Function = SRB_FUNCTION_EXECUTE_SCSI;

// set SenseInfoBufferLength.
Srb->SenseInfoBufferLength = 0x30;
// sense buffer is in aligned nonpaged pool.
senseInfoBuffer = ExAllocatePoolWithTag(NonPagedPoolCacheAligned,
0x30,‘yyh’);

if (senseInfoBuffer == NULL) {
//can not allocate pool,just return
KdPrint((“can not allocate the SenseInfoBuffer.\n”));
return(STATUS_INSUFFICIENT_RESOURCES);
}

Srb->SenseInfoBuffer = senseInfoBuffer;
Srb->DataBuffer = BufferAddress;
Srb->SrbFlags = fdoExtension->SrbFlags;
// Initialize the QueueAction field.
Srb->QueueAction = SRB_SIMPLE_TAG_REQUEST;

// Disable synchronous transfer for these requests.
SET_FLAG(Srb->SrbFlags, SRB_FLAGS_DISABLE_SYNCH_TRANSFER);
SET_FLAG(Srb->SrbFlags, SRB_FLAGS_NO_QUEUE_FREEZE);

// Set the event object to the unsignaled state.
// It will be used to signal request completion.
KeInitializeEvent(&event, NotificationEvent, FALSE);

// Build device I/O control request with METHOD_NEITHER data transfer.
// We’ll queue a completion routine to cleanup the MDL’s and such ourself.
irp = IoAllocateIrp(
(CCHAR) (fdoExtension->CommonExtension.LowerDeviceObject->StackSize + 1),
FALSE);

if(irp == NULL) {
ExFreePool(senseInfoBuffer);
DebugPrint((1, “ClassSendSrbSynchronous: Can’t allocate Irp\n”));
return(STATUS_INSUFFICIENT_RESOURCES);
}

// Get next stack location.
irpStack = IoGetNextIrpStackLocation(irp);

// Set up SRB for execute scsi request. Save SRB address in next stack
// for the port driver.
irpStack->MajorFunction = IRP_MJ_SCSI;
irpStack->Parameters.Scsi.Srb = Srb;

IoSetCompletionRoutine(irp,
IoSendSynchronousCompletion,
NULL,
TRUE,
TRUE,
TRUE);

ioStatus.Status = 0;
ioStatus.Information = 0;

irp->UserIosb = &ioStatus;
irp->UserEvent = &event;
if(BufferAddress&&BufferLength) {
irp->MdlAddress = IoAllocateMdl( BufferAddress,
BufferLength,
FALSE,
FALSE,
irp );
if (irp->MdlAddress == NULL) {
ExFreePool(senseInfoBuffer);
Srb->SenseInfoBuffer = NULL;
IoFreeIrp( irp );
DebugPrint((1, “ClassSendSrbSynchronous: Can’t allocate MDL\n”));
return STATUS_INSUFFICIENT_RESOURCES;
}

try {

// the io manager unlocks these pages upon completion
MmProbeAndLockPages( irp->MdlAddress,
KernelMode,
(WriteToDevice ? IoReadAccess:
IoWriteAccess));

} except(EXCEPTION_EXECUTE_HANDLER) {
status = GetExceptionCode();

ExFreePool(senseInfoBuffer);
Srb->SenseInfoBuffer = NULL;
IoFreeMdl(irp->MdlAddress);
IoFreeIrp(irp);

DebugPrint((1, "ClassSendSrbSynchronous: Exception %lx "
“locking buffer\n”, status));
return status;
}
}

// Set the transfer length.
Srb->DataTransferLength = BufferLength;

// Zero out status.
Srb->ScsiStatus = Srb->SrbStatus = 0;
Srb->NextSrb = 0;

// Set up IRP Address.
Srb->OriginalRequest = irp;

// Call the port driver with the request and wait for it to complete.
status = IoCallDriver(fdoExtension->CommonExtension.LowerDeviceObject, irp);

if (status == STATUS_PENDING)
{
//wait for the lower device to finish the IRP
status = KeWaitForSingleObject(&event, Executive, KernelMode, FALSE, NULL);//&WaitInterval);
status = ioStatus.Status;
}

…

}

that is the code, now i discard the irp->UserEvent, use context to pass the event to completion routine. Hope that will work well.

12

> now i discard the irp->UserEvent, use context to pass the event to completion routine.

Hope that will work well.

I am almost sure it will…

Anton Bassov

13

Unfortunately, that doesn’t work well, i still encounter the IRP was pending and never been completed.
the main modification like the following:
{
…
//irp->UserEvent = &event; //not use now
IoSetCompletionRoutine(irp,
IoSendSynchronousCompletion,
//NULL, //pass the address of the event
&event,
TRUE,
TRUE,
TRUE);

…

status = IoCallDriver(fdoExtension->CommonExtension.LowerDeviceObject, irp);

if (status == STATUS_PENDING)
{

DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“***********
Wait IRP to finished \n”);

status = KeWaitForSingleObject(&event, Executive, KernelMode, FALSE,
NULL);//&WaitInterval);
DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“*********** Wait IRP
success\n”);

status = ioStatus.Status;
}

…
}

the completion routine like the following:
{
PKEVENT event = (PKEVENT)Context;
//dump the message if we are called
DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,“***********completion routine has been called \n”);
// Unlock the pages for the data buffer.
if(Irp->MdlAddress) {
MmUnlockPages(Irp->MdlAddress);
IoFreeMdl(Irp->MdlAddress);
} // Signal the caller’s event.
//KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);
KeSetEvent(event, IO_NO_INCREMENT, FALSE);
// Free the IRP.
IoFreeIrp(Irp);

return STATUS_MORE_PROCESSING_REQUIRED;
}

When the IRP was pending, i not only don’t get the output for “DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,”*********** Wait IRP
success\n");“, but also not get the output for “DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,”***********completion routine has been called \n”);" in completion routine, this means the completion routine wasn’t called in the case that the IRP was pending and never been completed.

14

What may calls the completion routine never been called?

15

>When the IRP was pending, i not only don’t get the output for

“DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,”*********** Wait IRP
success\n");“, but also not get the output for
“DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL,”***********completion
routine has been called \n”);" in completion routine, this means the completion
routine wasn’t called in the case that the IRP was pending and never been
completed.

Bizzare…

To be honest, I just cannot suggest anything here…

Let’s see what other guys say - probably, someone may help you…

Anton Bassov

16

Hi, Anton Bassov:
Thanks a lot the same. Hope anyone can help…

17

I would not set ->UserEvent in the completion routine. Instead, I would
return STATUS_SUCCESS from it, and let IopCompleteRequest (the normal
completion path) to do this in a proper way.

–
Maxim Shatskih, Windows DDK MVP
StorageCraft Corporation
xxxxx@storagecraft.com
http://www.storagecraft.com

wrote in message news:xxxxx@ntdev…
> Oh, the completion routine like the following:
> {
> // Unlock the pages for the data buffer.
> if(Irp->MdlAddress) {
> MmUnlockPages(Irp->MdlAddress);
> IoFreeMdl(Irp->MdlAddress);
> } // Signal the caller’s event.
> KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);
>
> // Free the IRP.
> IoFreeIrp(Irp);
>
> return STATUS_MORE_PROCESSING_REQUIRED;
> }
>
> The things that confuses me is that in most times the IRP was completed
sucessfully, that me my completion routine was called in most cases, two
outputs all can be get in debug view, only sometimes, the IRP was pending, and
my completion routine was never been called, and the output for
DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL," *********** Wait IRP
> success\n") was not received, addtionally,this happens when
IRP_MN_START_DEVICE successfully been completed. In my opinion, all the request
sent to the device should be returned later, for i have set the timeout value
in srb, indeed, this work in most cases, i means for eg, when sending a command
to device, i unplug the device ,the request will return at certain time, the
time to wait to be returned is the timeout value in the srb.
> I don’t think that the IRP was not completed by the lower driver should
happen, but it occured.
>
>

18

> What is Irp->UserEvent??? I have never noticed any mentioning of this field
on

MSDN, so that, apparently, it is reserved for the system use.

Correct. It is the kernel mode representation of OVERLAPPED::hEvent.

It is signaled in IopCompleteRequest after copying Irp->IoStatus to user mode
area of Irp->UserIosb (OVERLAPPED::Internal and OVERLAPPED::InternalHigh), and
also maybe copying the data buffer to user mode (for buffered IO calls).

I would not touch ->UserEvent in my own code.

Normally if you want a completion routine to signal an event, you just pass it
as
‘Context’ parameter to IoSetCompletionRoutine().

Yes.

–
Maxim Shatskih, Windows DDK MVP
StorageCraft Corporation
xxxxx@storagecraft.com
http://www.storagecraft.com

19

> from the above code, can i say that i set the right event in the completion

routine?

Pass &event as Context to IoSetCompletionRoutine.

In the completion routine itself, signal (PKEVENT)Context.

–
Maxim Shatskih, Windows DDK MVP
StorageCraft Corporation
xxxxx@storagecraft.com
http://www.storagecraft.com

20

This is a driver allocated IRP, you do not want to let the io manager
complete it for you, it will bugcheck when it tries to a queue an apc to
the owning thread. The OP mistakenly used a field that was private to
the io manager and has since stopped

d

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Maxim S.
Shatskih
Sent: Wednesday, June 27, 2007 10:44 AM
To: Windows System Software Devs Interest List
Subject: Re:[ntdev] Why system lower driver never finish the IRP
sometimes?

I would not set ->UserEvent in the completion routine. Instead, I
would
return STATUS_SUCCESS from it, and let IopCompleteRequest (the normal
completion path) to do this in a proper way.

–
Maxim Shatskih, Windows DDK MVP
StorageCraft Corporation
xxxxx@storagecraft.com
http://www.storagecraft.com

wrote in message news:xxxxx@ntdev…
> Oh, the completion routine like the following:
> {
> // Unlock the pages for the data buffer.
> if(Irp->MdlAddress) {
> MmUnlockPages(Irp->MdlAddress);
> IoFreeMdl(Irp->MdlAddress);
> } // Signal the caller’s event.
> KeSetEvent(Irp->UserEvent, IO_NO_INCREMENT, FALSE);
>
> // Free the IRP.
> IoFreeIrp(Irp);
>
> return STATUS_MORE_PROCESSING_REQUIRED;
> }
>
> The things that confuses me is that in most times the IRP was
completed
sucessfully, that me my completion routine was called in most cases, two
outputs all can be get in debug view, only sometimes, the IRP was
pending, and
my completion routine was never been called, and the output for
DbgPrintEx(DPFLTR_IHVDRIVER_ID,DPFLTR_ERROR_LEVEL," *********** Wait IRP
> success\n") was not received, addtionally,this happens when
IRP_MN_START_DEVICE successfully been completed. In my opinion, all the
request
sent to the device should be returned later, for i have set the timeout
value
in srb, indeed, this work in most cases, i means for eg, when sending a
command
to device, i unplug the device ,the request will return at certain time,
the
time to wait to be returned is the timeout value in the srb.
> I don’t think that the IRP was not completed by the lower driver
should
happen, but it occured.
>
>

—
Questions? First check the Kernel Driver FAQ at
http://www.osronline.com/article.cfm?id=256

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