Bugcheck 0x44

Hi,

Can somebody please give me guidelines on how to find out what went wrong when a MULTIPLE_IRP_COMPLETE_REQUESTS (44) bugcheck happens?

I am debugging a 1394 WDM driver and the bugcheck happens every once in a while.

I’ve ran the usual !analyze -v command but it appears that the 1394ohci.sys driver tries to complete an IRP that was already completed.

I just can’t believe that the the ohci would have a bug of that nature. but I am just at a loss as to why this would happen since when the BSOD happens, the driver is in the process of detaching and reattaching the allocated buffers.

Any help would be GREATLY appreciated…so please help! :slight_smile:

Here is the output from !analyze -v

*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 44, {85113cc8, d64, 0, 0}

Probably caused by : ohci1394.sys ( ohci1394!OhciStartIo+9e3 )

Followup: MachineOwner

nt!RtlpBreakWithStatusInstruction:
8052b5ec cc int 3
0: kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

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: 85113cc8, Address of the IRP
Arg2: 00000d64
Arg3: 00000000
Arg4: 00000000

Debugging Details:

IRP_ADDRESS: 85113cc8

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0x44

PROCESS_NAME: Idle

LAST_CONTROL_TRANSFER: from 804f8e09 to 8052b5ec

STACK_TEXT:
80550ce8 804f8e09 00000003 80551044 00000000 nt!RtlpBreakWithStatusInstruction
80550d34 804f99f4 00000003 852140ac 85113cc8 nt!KiBugCheckDebugBreak+0x19
80551114 804f9f43 00000044 85113cc8 00000d64 nt!KeBugCheck2+0x574
80551134 804f18ec 00000044 85113cc8 00000d64 nt!KeBugCheckEx+0x1b
8055116c f76e8fa5 85113cc8 865cc028 00000000 nt!IopfCompleteRequest+0x2ce
805511a0 804f0100 865cc028 85113cc8 8521a488 ohci1394!OhciStartIo+0x9e3
805511c0 804f0328 865cc028 00000000 8055120c nt!IopStartNextPacket+0x56
805511d0 f76e8fb0 865cc028 00000000 864b5a50 nt!IoStartNextPacket+0x38
8055120c 804f0100 865cc028 864b5a50 00000000 ohci1394!OhciStartIo+0x9ee
8055122c 804f0328 865cc028 00000000 80551278 nt!IopStartNextPacket+0x56
8055123c f76e8fb0 865cc028 00000000 865cc028 nt!IoStartNextPacket+0x38
80551278 804f020d 865cc028 85113cc8 00000103 ohci1394!OhciStartIo+0x9ee
80551298 f76e944c 865cc028 85113cc8 00000000 nt!IoStartPacket+0x7d
805512d8 804ef19f 865cc028 85113cc8 8523e008 ohci1394!OhciIOCtl+0x3fc
805512e8 f76fcd79 80551314 f76fcfd6 86f7b2e8 nt!IopfCallDriver+0x31
805512f0 f76fcfd6 86f7b2e8 8523e008 85113cc8 1394BUS!Bus1394IsochChainToPort+0x1d
80551314 f76f8093 8523e008 85113cc8 865adb18 1394BUS!Bus1394DispatchIsochRequest+0x36
80551344 804ef19f 86f7b2e8 85113cc8 f7823580 1394BUS!Bus1394IOCtl+0x2b5
80551354 f78215df 865aa1e4 8523e008 865aa0d8 nt!IopfCallDriver+0x31
80551368 f781c90e 865ada60 85113cc8 8523e008 drvfw!SubmitIrp+0x9d
80551384 f781ccb1 857bc660 8521a488 000007ec drvfw!F_IsochRecycleBuffers+0x18a
805513b4 f76ec723 865aa1e4 00000002 80545420 drvfw!IsochCallback+0x327
805513ec f76ed344 865cc0e0 00000000 00000000 ohci1394!OhciHandleIsochInt+0x21d
80551428 80545e7f 865cd624 865cc0e0 00000000 ohci1394!OhciIsochDpc+0x68
80551450 80545d64 00000000 0000000e 00000000 nt!KiRetireDpcList+0x61
80551454 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x28

STACK_COMMAND: kb

FOLLOWUP_IP:
ohci1394!OhciStartIo+9e3
f76e8fa5 6a00 push 0

SYMBOL_STACK_INDEX: 5

SYMBOL_NAME: ohci1394!OhciStartIo+9e3

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: ohci1394

IMAGE_NAME: ohci1394.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 480254fa

FAILURE_BUCKET_ID: 0x44_ohci1394!OhciStartIo+9e3

BUCKET_ID: 0x44_ohci1394!OhciStartIo+9e3

Followup: MachineOwner

Is this on Vista and later by any chance? If so, you could try the Verifier
IRP log (!verifier 100 irp). Haven’t tried using this yet, but I’ve been
using the pool allocation log with much success lately so thought I’d
mention.

-scott


Scott Noone
Consulting Associate
OSR Open Systems Resources, Inc.
http://www.osronline.com

wrote in message news:xxxxx@windbg…
> Hi,
>
> Can somebody please give me guidelines on how to find out what went wrong
> when a MULTIPLE_IRP_COMPLETE_REQUESTS (44) bugcheck happens?
>
> I am debugging a 1394 WDM driver and the bugcheck happens every once in a
> while.
>
> I’ve ran the usual !analyze -v command but it appears that the
> 1394ohci.sys driver tries to complete an IRP that was already completed.
>
> I just can’t believe that the the ohci would have a bug of that nature.
> but I am just at a loss as to why this would happen since when the BSOD
> happens, the driver is in the process of detaching and reattaching the
> allocated buffers.
>
> Any help would be GREATLY appreciated…so please help! :slight_smile:
>
> Here is the output from !analyze -v
>
> ***
> *
>
> * Bugcheck Analysis
>
> *
>
>

>
> Use !analyze -v to get detailed debugging information.
>
> BugCheck 44, {85113cc8, d64, 0, 0}
>
> Probably caused by : ohci1394.sys ( ohci1394!OhciStartIo+9e3 )
>
> Followup: MachineOwner
> ---------
>
> nt!RtlpBreakWithStatusInstruction:
> 8052b5ec cc int 3
> 0: kd> !analyze -v
> ***
> *
>
> * Bugcheck Analysis
>
> *
>
>

>
> 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: 85113cc8, Address of the IRP
> Arg2: 00000d64
> Arg3: 00000000
> Arg4: 00000000
>
> Debugging Details:
> ------------------
>
>
> IRP_ADDRESS: 85113cc8
>
> DEFAULT_BUCKET_ID: DRIVER_FAULT
>
> BUGCHECK_STR: 0x44
>
> PROCESS_NAME: Idle
>
> LAST_CONTROL_TRANSFER: from 804f8e09 to 8052b5ec
>
> STACK_TEXT:
> 80550ce8 804f8e09 00000003 80551044 00000000
> nt!RtlpBreakWithStatusInstruction
> 80550d34 804f99f4 00000003 852140ac 85113cc8 nt!KiBugCheckDebugBreak+0x19
> 80551114 804f9f43 00000044 85113cc8 00000d64 nt!KeBugCheck2+0x574
> 80551134 804f18ec 00000044 85113cc8 00000d64 nt!KeBugCheckEx+0x1b
> 8055116c f76e8fa5 85113cc8 865cc028 00000000 nt!IopfCompleteRequest+0x2ce
> 805511a0 804f0100 865cc028 85113cc8 8521a488 ohci1394!OhciStartIo+0x9e3
> 805511c0 804f0328 865cc028 00000000 8055120c nt!IopStartNextPacket+0x56
> 805511d0 f76e8fb0 865cc028 00000000 864b5a50 nt!IoStartNextPacket+0x38
> 8055120c 804f0100 865cc028 864b5a50 00000000 ohci1394!OhciStartIo+0x9ee
> 8055122c 804f0328 865cc028 00000000 80551278 nt!IopStartNextPacket+0x56
> 8055123c f76e8fb0 865cc028 00000000 865cc028 nt!IoStartNextPacket+0x38
> 80551278 804f020d 865cc028 85113cc8 00000103 ohci1394!OhciStartIo+0x9ee
> 80551298 f76e944c 865cc028 85113cc8 00000000 nt!IoStartPacket+0x7d
> 805512d8 804ef19f 865cc028 85113cc8 8523e008 ohci1394!OhciIOCtl+0x3fc
> 805512e8 f76fcd79 80551314 f76fcfd6 86f7b2e8 nt!IopfCallDriver+0x31
> 805512f0 f76fcfd6 86f7b2e8 8523e008 85113cc8
> 1394BUS!Bus1394IsochChainToPort+0x1d
> 80551314 f76f8093 8523e008 85113cc8 865adb18
> 1394BUS!Bus1394DispatchIsochRequest+0x36
> 80551344 804ef19f 86f7b2e8 85113cc8 f7823580 1394BUS!Bus1394IOCtl+0x2b5
> 80551354 f78215df 865aa1e4 8523e008 865aa0d8 nt!IopfCallDriver+0x31
> 80551368 f781c90e 865ada60 85113cc8 8523e008 drvfw!SubmitIrp+0x9d
> 80551384 f781ccb1 857bc660 8521a488 000007ec
> drvfw!F_IsochRecycleBuffers+0x18a
> 805513b4 f76ec723 865aa1e4 00000002 80545420 drvfw!IsochCallback+0x327
> 805513ec f76ed344 865cc0e0 00000000 00000000
> ohci1394!OhciHandleIsochInt+0x21d
> 80551428 80545e7f 865cd624 865cc0e0 00000000 ohci1394!OhciIsochDpc+0x68
> 80551450 80545d64 00000000 0000000e 00000000 nt!KiRetireDpcList+0x61
> 80551454 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x28
>
>
> STACK_COMMAND: kb
>
> FOLLOWUP_IP:
> ohci1394!OhciStartIo+9e3
> f76e8fa5 6a00 push 0
>
> SYMBOL_STACK_INDEX: 5
>
> SYMBOL_NAME: ohci1394!OhciStartIo+9e3
>
> FOLLOWUP_NAME: MachineOwner
>
> MODULE_NAME: ohci1394
>
> IMAGE_NAME: ohci1394.sys
>
> DEBUG_FLR_IMAGE_TIMESTAMP: 480254fa
>
> FAILURE_BUCKET_ID: 0x44_ohci1394!OhciStartIo+9e3
>
> BUCKET_ID: 0x44_ohci1394!OhciStartIo+9e3
>
> Followup: MachineOwner
> ---------
>
>

Hi Scott,

Thanks for replying. Long time no hear…I was in one of your OSR training classes. Anyhow the system is actually running XPSP3. For the life in me I cannot see what is causing the problem. I’ve ran sdv and it does catch a markirppending2 fault but it is in the IRP_MJ_CLEANUP handler.

> I was in one of your OSR training classes

Can’t be, you wouldn’t have had any bugs if that were the case :slight_smile:

If you haven’t already, I’d start by enabling Verifier on your driver and
the 1394HC driver. That might catch something earlier that will be easier to
diagnose.

Also, the call stack here looks like there might be some kind of error
condition (the repeated IoStartNextPacket calls look suspicious). Though I
must admit I’ve never done anything in the 1394 stack so it could be normal.
What status is in Irp->IoStatus.Status?

Another step to diagnosis might be loaded the checked version of
ohci1394.sys on the system. Maybe you’ll trigger an ASSERT or get some kind
of debug output.

-scott


Scott Noone
Consulting Associate
OSR Open Systems Resources, Inc.
http://www.osronline.com

wrote in message news:xxxxx@windbg…
> Hi Scott,
>
> Thanks for replying. Long time no hear…I was in one of your OSR training
> classes. Anyhow the system is actually running XPSP3. For the life in me I
> cannot see what is causing the problem. I’ve ran sdv and it does catch a
> markirppending2 fault but it is in the IRP_MJ_CLEANUP handler.
>
>
>

>Can’t be, you wouldn’t have had any bugs if that were the case :slight_smile:

I guess anything is possible then :slight_smile:

What status is in Irp->IoStatus.Status?

I am not sure now. I added another wmi tracing message to F_IsochRecycleBuffers to get additional information and now I am waiting for the system to bugcheck. As soon as it does I’ll look and see and post the results.

…loaded the checked version of ohci1394.sys on the system

I’m running the free build environment. Can that still be done with

ed ohci1394!OhciDebugLevel 2

Thanks,

Another thing to consider is that you are the one who is completing the PIRP in question too early and the 1394 core is the one being blamed for the double completion. This typically happens when you cancel an irp and assume it completes synchronously, when in fact the completion for the cancelation never occurs or happens asynchronously later

d

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Scott Noone
Sent: Tuesday, July 28, 2009 4:09 AM
To: Kernel Debugging Interest List
Subject: Re:[windbg] Bugcheck 0x44

I was in one of your OSR training classes

Can’t be, you wouldn’t have had any bugs if that were the case :slight_smile:

If you haven’t already, I’d start by enabling Verifier on your driver and
the 1394HC driver. That might catch something earlier that will be easier to
diagnose.

Also, the call stack here looks like there might be some kind of error
condition (the repeated IoStartNextPacket calls look suspicious). Though I
must admit I’ve never done anything in the 1394 stack so it could be normal.
What status is in Irp->IoStatus.Status?

Another step to diagnosis might be loaded the checked version of
ohci1394.sys on the system. Maybe you’ll trigger an ASSERT or get some kind
of debug output.

-scott


Scott Noone
Consulting Associate
OSR Open Systems Resources, Inc.
http://www.osronline.com

wrote in message news:xxxxx@windbg…
> Hi Scott,
>
> Thanks for replying. Long time no hear…I was in one of your OSR training
> classes. Anyhow the system is actually running XPSP3. For the life in me I
> cannot see what is causing the problem. I’ve ran sdv and it does catch a
> markirppending2 fault but it is in the IRP_MJ_CLEANUP handler.
>
>
>


WINDBG 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