22.2.13 All Test Case Threads Must Complete/Finish

Hi people,

I can’t find any where what the fail below in Device Path Exercier test under DTM means:
“22.2.13 All Test Case Threads Must Complete/Finish” Fail.
What exactly is test 22.2.13 checking for?
What is my KMDF USB driver doing/not doing to cause this fail?
Is there a way to get this test to show more detail on this fail then just this one line ?
or the specific IOCTL/command it is sending to cause this?
is the fail message above related to this timeout message below I see durring the test
“DevPathExer has stopped making progress…Attempting to resume thread”

Thanks for any clarification/Jose

Still waiting for some one that would kindly give me a clue here.
I am testing a USB driver writen w/ KMDF 1.7 and I am testing it with WLK 1.7
All unclasified tests have passed execpt for Device Path Exerciser which fails after
430 passes on “22.2.13 All Test Case Threads Must Complete/Finish”
Where can I find out what this means so I can fix what ever it is ?

Thank you, Jose

You can run the utility manually and see if it is passing or failing. it
will generate a log file for each IOCTL that has been passed to the driver
and that has succeeded or failed.you might be able to trace the exact IOCTL
when run manually. try running this with driver verifier enabled as
mentioned in the following page
http://msdn.microsoft.com/en-us/library/ms792487.aspx

-rtshiva
On Wed, Aug 12, 2009 at 8:46 PM, wrote:

> Still waiting for some one that would kindly give me a clue here.
> I am testing a USB driver writen w/ KMDF 1.7 and I am testing it with WLK
> 1.7
> All unclasified tests have passed execpt for Device Path Exerciser which
> fails after
> 430 passes on “22.2.13 All Test Case Threads Must Complete/Finish”
> Where can I find out what this means so I can fix what ever it is ?
>
> Thank you, Jose
>
>
> —
> 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
>

Are you perhaps not completing an IRP?

Not a very helpful answer, I know, but that’s what the description sounds like and there doesn’t seem to be anything in the docs.

I’ve mercifully been spared from the WLK to date, but have you checked to see if there are any updates or QFE’s or something. The first thing is that I don’t think that the WLK follows the same verison numbering scheme as KMDF/WDK, so I wonder if you have the most recent version. The second thing is that it seems the WLK has a history of not, you know, working, so I would check for updates for that reason as well, and maybe there’s some new docs, if nothing else.

Good luck,

mm

As mm suggested, possibly a thread is unable to exit b/c of a pending I/O queued to the thread.

Look if there are pending IRPs in your KMDF driver (!wdfdriverinfo - will print wdfdevice, !wdfdevicequeues - see if any queue shows outstanding requests owned by your driver, !wdfrequest to dump the request details).

HTH,
Praveen

Thank you so much rtshiva, MM and Praveen,

The extra debug messages to the DIAGS.log file has help a lot. The test timeout are being caused by err 0x103 (i.e. STATUS_PENDING). see log text below:

ZwWriteFile, Buffer=0x01080BD0, Length=0. Offset=0x0
ZwWriteFile Complete Status=0x103

What I dont understand is that my driver is actually always returning a Timeout via call WdfRequestCompleteWithInformation() so why is STATUS_PENDING appearing instead in the DevPathExer’s diags.log file ?
See code below where I always return sychronously from OsrFxEvtIoWrite() :

/****** commented this out
WdfRequestSetCompletionRoutine(
Request,
EvtRequestWriteCompletionRoutine,
pipe);
*/
WDF_REQUEST_SEND_OPTIONS_INIT( &RequestOptions, WDF_REQUEST_SEND_OPTION_SYNCHRONOUS );
WDF_REQUEST_SEND_OPTIONS_SET_TIMEOUT( &RequestOptions, WDF_REL_TIMEOUT_IN_SEC(1) );

//
// Send the request synchronously.
//
if (WdfRequestSend(Request, WdfUsbTargetPipeGetIoTarget(pipe), &RequestOptions) == FALSE) {
//
// Framework couldn’t send the request for some reason.
//
TraceEvents(TRACE_LEVEL_ERROR, DBG_WRITE, “WdfRequestSend failed\n”);
// status = WdfRequestGetStatus(Request); // <– NEVER PRINTS
//goto Exit;
}

WDF_REQUEST_COMPLETION_PARAMS CompletionParams;
PWDF_USB_REQUEST_COMPLETION_PARAMS usbCompletionParams;

WDF_REQUEST_COMPLETION_PARAMS_INIT(&CompletionParams);
WdfRequestGetCompletionParams(
Request,
&CompletionParams
);

status = CompletionParams.IoStatus.Status;

usbCompletionParams = CompletionParams.Parameters.Usb.Completion;

bytesWritten = usbCompletionParams->Parameters.PipeWrite.Length;

if (NT_SUCCESS(status)){
TraceEvents(TRACE_LEVEL_INFORMATION, DBG_WRITE,
“Number of bytes written: %I64d\n”, (INT64)bytesWritten);
} else {
// <– THIS MSG DOES PRINT W/ STATUS=0xC00000B5
TraceEvents(TRACE_LEVEL_ERROR, DBG_WRITE,
“Write failed: request Status 0x%x UsbdStatus 0x%x bytesWritten %d\n”,
status, usbCompletionParams->UsbdStatus, bytesWritten);
}

Exit:
WdfRequestCompleteWithInformation(Request, status, bytesWritten);

// if (!NT_SUCCESS(status)) {
// WdfRequestCompleteWithInformation(Request, status, 0);
// }

TraceEvents(TRACE_LEVEL_INFORMATION, DBG_WRITE, “<– OsrFxEvtIoWrite\n”);

return;

}

xxxxx@camtech.com wrote:

Thank you so much rtshiva, MM and Praveen,

The extra debug messages to the DIAGS.log file has help a lot. The test timeout are being caused by err 0x103 (i.e. STATUS_PENDING). see log text below:

ZwWriteFile, Buffer=0x01080BD0, Length=0. Offset=0x0
ZwWriteFile Complete Status=0x103

What I dont understand is that my driver is actually always returning a Timeout via call WdfRequestCompleteWithInformation() so why is STATUS_PENDING appearing instead in the DevPathExer’s diags.log file ?
See code below where I always return sychronously from OsrFxEvtIoWrite() :

Every request coming into a KMDF driver is completed with STATUS_PENDING
when it gets placed into a queue. You should see another completion
notice later, when your completion routine finally runs. You’re sure
the request eventually completes?

I suppose it’s possible that the application assumes that a ZwWriteFile
for 0 bytes will complete immediately, but that would be a buggy
application. The only way to handle that would be to use an
IoInCallerContext preprocessor.


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

> my driver is actually always returning a Timeout via call WdfRequestCompleteWithInformation()

// <– THIS MSG DOES PRINT W/ STATUS=0xC00000B5

Which may be the problem. Possibly test wants the request to complete fairly quickly. It is probably checking for threads to exit before you complete the request with timeout.

Praveen

This is a total guess.

Doesn’t this test turn on Driver Verifier? If so could it be the result of Forced Pending I/O Requests or something like that?

mm

Guys again thank you all for your replies,

I am working under WinXP and the Verifier doc says it only supports Forced Pending I/O Requests for Vista so I dont think I am using that (Also Verifier’s Enhanced I/O verification is set to NO).

I took the original KMDF USB sample driver and changed it from Asynchronous to Synchronus responses w/ a 1 second timeout. Hopefuly the code I included on the previous msg shows whether my implementation is correct.
During DevPathExer testing the driver initially completes about 2700 IoWrite commands before the hardware starts to time them out. (I can see these debug msgs via the DebugView app).

GSIUSBLT2: –>OsrFxEvtIoWrite Length 221
GSIUSBLT2: Number of bytes written: 221
GSIUSBLT2: <– OsrFxEvtIoWrite
GSIUSBLT2: –>OsrFxEvtIoWrite Length 222
GSIUSBLT2: Write failed: request Status 0xc00000b5 UsbdStatus 0x0 bytesWritten 0
GSIUSBLT2: <– OsrFxEvtIoWrite

Are you guys saying that KMDF is returning an imimidiate STATUS_PENDING before passing the IoWrite call to my driver and them when I return w/ the WdfRequestCompleteWithInformation() a second later it is too late for the DevPathExer test app because it has terminated its own wait thread ? or did I missunderstand completely?

Thanks/Jose

My intention was to block the apps till the IoCalls where complete. I will try and revert back to Asychronous to see if it fixes the testing problems.

OK,
I changed my IoWrite routine back to Asychronous by calling WdfRequestSetCompletionRoutine() and removing the send Synchronous w/ timeout option from WdfRequestSend(). Now, when the IoWrite does not succeed at the device the driver debug msg shows CancelIO instead of Timeout.
GSIUSBLT2: Write failed: request Status 0xc0000120 UsbdStatus 0x0 bytesWritten 0
This probably means DevPathExer app is waiting for an IoComplete for a short period, shorter then my driver’s timeout period, before it sends a CancelIO to the driver. My IoWrite routine never saw the CancelIO while it was waiting for the Asychronous timeout. And DevPathExer never saw my IoComplete(w/ Timeout) because it bailed out too quick.
The final result is that “22.2.13 All Test Case Threads Must Complete/Finish” now does pass because now the DevPathExer does see my IoComplete(w/ CancelIO).

This driver change means that it is up to the calling app. to set a timeout to handle the case where the device does not respond to a driver IO call and to send a driver CancellIO after that timeout.

Again could not have figured it out w/o your comments.

Jose