Multiple IRP completions

daniel_sela · September 30, 2014, 3:15am

Hey all,
I’m working on a set of filter drivers - registry callback, FS filter and WFP callout.
In all of these I dont create IRPs of my own and neither I call IoCompleteRequest.

I got a MULTIPLE_IRP_COMPLETE_REQUESTS bugcheck on windows 7 64bit after a long time running the drivers.
How can I determine if my drivers have anything to do with it?

Following is the 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: fffffa80bae82bd0, Address of the IRP
Arg2: 0000000000000eae
Arg3: 0000000000000000
Arg4: 0000000000000000

Debugging Details:

IRP_ADDRESS: fffffa80bae82bd0

FOLLOWUP_IP:
hidusb!HumCallUSB+2c1
fffff880`0cae23f5 3bde cmp ebx,esi

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0x44

PROCESS_NAME: System

CURRENT_IRQL: 0

LAST_CONTROL_TRANSFER: from fffff800038628c0 to fffff80003879bc0

STACK_TEXT:
fffff880035cb908 fffff800038628c0 : 0000000000000044 fffffa80bae82bd0 0000000000000eae 0000000000000000 : nt!KeBugCheckEx
fffff880035cb910 fffff8800cae23f5 : 0000000000000103 0000000000000103 fffffa80bae82e00 fffffa80b9f85400 : nt! ?? ::FNODOBFM::string'+0x413f2 fffff880035cba00 fffff8800cae7768 : fffffa8084eae438 0000000000000028 fffffa8084eae060 00000000000007ff : hidusb!HumCallUSB+0x2c1 fffff880035cbaa0 fffff8800cae06d6 : fffffa8084eae060 0000000000000000 fffffa80ba99d010 fffff80003a1f2d8 : hidusb!HumAbortPendingRequests+0x74 fffff880035cbae0 fffff80003b70c93 : fffffa8084eae060 0000000000000003 fffff80003a1f2d8 fffffa80036ef660 : hidusb!HumResetWorkItem+0x92 fffff880035cbb40 fffff80003883261 : fffff80003a1f200 fffff80003b70c01 fffffa80036ef600 fffff80003a1f2d8 : nt!IopProcessWorkItem+0x23 fffff880035cbb70 fffff80003b1573a : 0000000000000000 fffffa80036ef660 0000000000000080 fffffa80036dc9e0 : nt!ExpWorkerThread+0x111 fffff880035cbc00 fffff8000386a8e6 : fffff880033d7180 fffffa80036ef660 fffff880033e1fc0 0000000000000000 : nt!PspSystemThreadStartup+0x5a fffff880035cbc40 0000000000000000 : fffff880035cc000 fffff880035c6000 fffff880035cb750 00000000`00000000 : nt!KiStartSystemThread+0x16

STACK_COMMAND: kb

SYMBOL_STACK_INDEX: 2

SYMBOL_NAME: hidusb!HumCallUSB+2c1

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: hidusb

IMAGE_NAME: hidusb.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4ce7a665

FAILURE_BUCKET_ID: X64_0x44_hidusb!HumCallUSB+2c1

BUCKET_ID: X64_0x44_hidusb!HumCallUSB+2c1

Followup: MachineOwner

Thank you very much,
Daniel

Mark_Roddy · September 30, 2014, 7:47am

You are not filtering or otherwise involved in the usb or usbhid stacks? If
so it is unlikely but still possible that you are involved. Turn driver
verifier on for all of your drivers and for the stack that failed and see
what happens. Keep a log of the last N irps processed by your code and see
if that shows anything. Bump up the verbosity of your runtime logging and
track your actions that way.

Mark Roddy

On Tue, Sep 30, 2014 at 3:15 AM, wrote:

> Hey all,
> I’m working on a set of filter drivers - registry callback, FS filter and
> WFP callout.
> In all of these I dont create IRPs of my own and neither I call
> IoCompleteRequest.
>
> I got a MULTIPLE_IRP_COMPLETE_REQUESTS bugcheck on windows 7 64bit after a
> long time running the drivers.
> How can I determine if my drivers have anything to do with it?
>
> Following is the 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: fffffa80bae82bd0, Address of the IRP
> Arg2: 0000000000000eae
> Arg3: 0000000000000000
> Arg4: 0000000000000000
>
> Debugging Details:
> ------------------
>
>
> IRP_ADDRESS: fffffa80bae82bd0
>
> FOLLOWUP_IP:
> hidusb!HumCallUSB+2c1
> fffff8800cae23f5 3bde cmp ebx,esi > > DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT > > BUGCHECK_STR: 0x44 > > PROCESS_NAME: System > > CURRENT_IRQL: 0 > > LAST_CONTROL_TRANSFER: from fffff800038628c0 to fffff80003879bc0 > > STACK_TEXT: > fffff880035cb908 fffff800038628c0 : 0000000000000044 fffffa80bae82bd0 > 0000000000000eae 0000000000000000 : nt!KeBugCheckEx > fffff880035cb910 fffff8800cae23f5 : 0000000000000103 0000000000000103 > fffffa80bae82e00 fffffa80b9f85400 : nt! ?? ::FNODOBFM::string’+0x413f2
> fffff880035cba00 fffff8800cae7768 : fffffa8084eae438 0000000000000028
> fffffa8084eae060 00000000000007ff : hidusb!HumCallUSB+0x2c1
> fffff880035cbaa0 fffff8800cae06d6 : fffffa8084eae060 0000000000000000
> fffffa80ba99d010 fffff80003a1f2d8 : hidusb!HumAbortPendingRequests+0x74
> fffff880035cbae0 fffff80003b70c93 : fffffa8084eae060 0000000000000003
> fffff80003a1f2d8 fffffa80036ef660 : hidusb!HumResetWorkItem+0x92
> fffff880035cbb40 fffff80003883261 : fffff80003a1f200 fffff80003b70c01
> fffffa80036ef600 fffff80003a1f2d8 : nt!IopProcessWorkItem+0x23
> fffff880035cbb70 fffff80003b1573a : 0000000000000000 fffffa80036ef660
> 0000000000000080 fffffa80036dc9e0 : nt!ExpWorkerThread+0x111
> fffff880035cbc00 fffff8000386a8e6 : fffff880033d7180 fffffa80036ef660
> fffff880033e1fc0 0000000000000000 : nt!PspSystemThreadStartup+0x5a
> fffff880035cbc40 0000000000000000 : fffff880035cc000 fffff880035c6000
> fffff880035cb750 0000000000000000 : nt!KiStartSystemThread+0x16
>
>
> STACK_COMMAND: kb
>
> SYMBOL_STACK_INDEX: 2
>
> SYMBOL_NAME: hidusb!HumCallUSB+2c1
>
> FOLLOWUP_NAME: MachineOwner
>
> MODULE_NAME: hidusb
>
> IMAGE_NAME: hidusb.sys
>
> DEBUG_FLR_IMAGE_TIMESTAMP: 4ce7a665
>
> FAILURE_BUCKET_ID: X64_0x44_hidusb!HumCallUSB+2c1
>
> BUCKET_ID: X64_0x44_hidusb!HumCallUSB+2c1
>
> Followup: MachineOwner
>
> Thank you very much,
> Daniel
>
> —
> NTDEV is sponsored by OSR
>
> Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev
>
> OSR is HIRING!! See http://www.osr.com/careers
>
> 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
>

daniel_sela · September 30, 2014, 8:08am

Hey Mark,
Thanks for your replay.

Could it be that the usb stack driver perform FS/registry operations?
If so - my drivers should filter these operations (not complete them though).
Otherwise - as far as I know - I’m not involved in the USB / USBHID stacks.

Will turn the verifier’s IRP logging on, any other relevant setting?

Thank you,
Daniel

Doron_Holan · September 30, 2014, 9:41am

These drivers do registry operations

d

Bent from my phone

From: xxxxx@comsecglobal.com mailto:xxxxx
Sent: ?9/?30/?2014 5:08 AM
To: Windows System Software Devs Interest Listmailto:xxxxx
Subject: RE:[ntdev] Multiple IRP completions

Hey Mark,
Thanks for your replay.

Could it be that the usb stack driver perform FS/registry operations?
If so - my drivers should filter these operations (not complete them though).
Otherwise - as far as I know - I’m not involved in the USB / USBHID stacks.

Will turn the verifier’s IRP logging on, any other relevant setting?

Thank you,
Daniel

—
NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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</mailto:xxxxx></mailto:xxxxx>

daniel_sela · September 30, 2014, 10:52am

Is it possible that my driver takes too long to process the request and that makes some other driver timeout fallback to complete the request by itself and then when my driver finishes processing another driver completes the request as well?

Or a more general question - what can my driver do that will make 2 drivers complete the same IRP, assuming I dont call IoCompleteRequest myself?

Thanks,
Daniel

Doron_Holan · September 30, 2014, 11:56am

Two things come to mind. First you introduce a new error code. Second you change the timing, causing a race in the driver

d

Bent from my phone

From: xxxxx@comsecglobal.com mailto:xxxxx
Sent: ?9/?30/?2014 7:53 AM
To: Windows System Software Devs Interest Listmailto:xxxxx
Subject: RE:[ntdev] Multiple IRP completions

Is it possible that my driver takes too long to process the request and that makes some other driver timeout fallback to complete the request by itself and then when my driver finishes processing another driver completes the request as well?

Or a more general question - what can my driver do that will make 2 drivers complete the same IRP, assuming I dont call IoCompleteRequest myself?

Thanks,
Daniel

—
NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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</mailto:xxxxx></mailto:xxxxx>

Scott_Noone_OSR · September 30, 2014, 3:26pm

It’s also possible that you’ve corrupted the IRP structure in memory in such
a way that you’re triggering the multiple IRP complete requests bugcheck.
Can you post the output of “!irp fffffa80bae82bd0 1”?

In terms of which Verifier settings to enable, you want everything but the
Low Resource Simulation related options. Note that if you turn IRP logging
on you can dump the Verifier IRP Log with !verifier 100 from the debugger,
this can be helpful in finding the multiple calls to IoCompleteRequest.

-scott
OSR
@OSRDrivers

wrote in message news:xxxxx@ntdev…

Is it possible that my driver takes too long to process the request and that
makes some other driver timeout fallback to complete the request by itself
and then when my driver finishes processing another driver completes the
request as well?

Or a more general question - what can my driver do that will make 2 drivers
complete the same IRP, assuming I dont call IoCompleteRequest myself?

Thanks,
Daniel

daniel_sela · October 1, 2014, 2:31am

@Doron -
What do you mean by saying that I introduce a new error code?
I dont have any code that changes the time, waiting on events for a period of time is the only place I consider time in any way.

@Scott -
The output of the command is:
2: kd> !irp fffffa80bae82bd0 1
IRP signature does not match, probably not an IRP

Should I conclude from it that I over-wrote the IRP’s signature in memory and that’s what caused the completion mark?

Thanks,
Daniel

Doron_Holan · October 1, 2014, 2:43am

If your registry filter denies access or reads/writes when otherwise it would succeed without your filter being present, you are introducing new error values back to the caller

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@comsecglobal.com
Sent: Tuesday, September 30, 2014 11:31 PM
To: Windows System Software Devs Interest List
Subject: RE:[ntdev] Multiple IRP completions

@Doron -
What do you mean by saying that I introduce a new error code?
I dont have any code that changes the time, waiting on events for a period of time is the only place I consider time in any way.

@Scott -
The output of the command is:
2: kd> !irp fffffa80bae82bd0 1
IRP signature does not match, probably not an IRP

Should I conclude from it that I over-wrote the IRP’s signature in memory and that’s what caused the completion mark?

Thanks,
Daniel

NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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

Scott_Noone_OSR · October 1, 2014, 9:42am

Not necessarily, the Type field might also be cleared as part of freeing the
IRP. You should look at the rest of the IRP structure and see if the memory
is filled with a pattern that might trace back to your driver (“dt nt!_IRP
fffffa80bae82bd0”, “dc fffffa80bae82bd0”). Also, what does “!pool
fffffa80bae82bd0” say?

Have you turned Verifier on yet?

-scott
OSR
@OSRDrivers

wrote in message news:xxxxx@ntdev…

@Doron -
What do you mean by saying that I introduce a new error code?
I dont have any code that changes the time, waiting on events for a period
of time is the only place I consider time in any way.

@Scott -
The output of the command is:
2: kd> !irp fffffa80bae82bd0 1
IRP signature does not match, probably not an IRP

Should I conclude from it that I over-wrote the IRP’s signature in memory
and that’s what caused the completion mark?

Thanks,
Daniel

daniel_sela · October 1, 2014, 10:36am

Hey guys,
Thanks for the responses.

@Doron -
I do not block any request neither introducing a new error value in these drivers.

@Scott -
The output for dt nt!_IRP fffffa80bae82bd0 is:
+0x000 Type : 0n13296
+0x002 Size : 0xba57
+0x008 MdlAddress : (null)
+0x010 Flags : 0x60000
+0x018 AssociatedIrp :
+0x020 ThreadListEntry : _LIST_ENTRY [0xfffffa80bae82bf0 - 0xfffffa80bae82bf0]
+0x030 IoStatus : _IO_STATUS_BLOCK
+0x040 RequestorMode : 0 ‘’
+0x041 PendingReturned : 0x1 ‘’
+0x042 StackCount : 8 ‘’
+0x043 CurrentLocation : 10 ‘’
+0x044 Cancel : 0 ‘’
+0x045 CancelIrql : 0 ‘’
+0x046 ApcEnvironment : 0 ‘’
+0x047 AllocationFlags : 0x4 ‘’
+0x048 UserIosb : 0xfffff880035cba50 _IO_STATUS_BLOCK +0x050 UserEvent : 0xfffff880035cba60 _KEVENT
+0x058 Overlay :
+0x068 CancelRoutine : (null)
+0x070 UserBuffer : (null)
+0x078 Tail :

and the output for dc fffffa80bae82bd0 is:
fffffa80bae82bd0 ba5733f0 fffffa80 00000000 00000000 .3W............. fffffa80bae82be0 00060000 00000000 00000000 00000000 …
fffffa80bae82bf0 bae82bf0 fffffa80 bae82bf0 fffffa80 .+.......+...... fffffa80bae82c00 00000000 00000000 00000430 00000000 …0…
fffffa80bae82c10 0a080100 04000000 035cba50 fffff880 ........P.\..... fffffa80bae82c20 035cba60 fffff880 00000000 00000000 .\............. fffffa80bae82c30 00000000 00000000 00000000 00000000 …
fffffa80`bae82c40 00000000 00000000 00580012 00000000 …X…

as I said, I never set a request to IO_STATUS_BLOCK.

the output for !pool fffffa80bae82bd0 is:
Pool page fffffa80bae82bd0 region is Unknown
fffffa80bae82000 size: 30 previous size: 0 (Allocated) vEBR
fffffa80bae82030 size: 20 previous size: 30 (Free) …
fffffa80bae82050 size: 30 previous size: 20 (Allocated) vEBR
fffffa80bae82080 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae820b0 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae820e0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82110 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae82140 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82170 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae821a0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae821d0 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae82200 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82230 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82260 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82290 size: 10 previous size: 30 (Free) CcSc
fffffa80bae822a0 size: 30 previous size: 10 (Allocated) hlab
fffffa80bae822d0 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae82300 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82330 size: 20 previous size: 30 (Free) mneS
fffffa80bae82350 size: 30 previous size: 20 (Allocated) vEBR
fffffa80bae82380 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae823b0 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae823e0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82410 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82440 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82470 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae824a0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae824d0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82500 size: 60 previous size: 30 (Free ) MmRl
fffffa80bae82560 size: 30 previous size: 60 (Allocated) hlab
fffffa80bae82590 size: 30 previous size: 30 (Allocated) ReEv
fffffa80bae825c0 size: 10 previous size: 30 (Free) NpFr
fffffa80bae825d0 size: 30 previous size: 10 (Allocated) hlab
fffffa80bae82600 size: 20 previous size: 30 (Free) mneS
fffffa80bae82620 size: 30 previous size: 20 (Allocated) hlab
fffffa80bae82650 size: 30 previous size: 30 (Allocated) vEBR
fffffa80bae82680 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae826b0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae826e0 size: 20 previous size: 30 (Free) Irp
fffffa80bae82700 size: 30 previous size: 20 (Allocated) hlab
fffffa80bae82730 size: 10 previous size: 30 (Free) MFE0
fffffa80bae82740 size: 50 previous size: 10 (Allocated) VadS
fffffa80bae82790 size: 30 previous size: 50 (Allocated) hlab
fffffa80bae827c0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae827f0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82820 size: 20 previous size: 30 (Free) MFE0
fffffa80bae82840 size: 30 previous size: 20 (Allocated) hlab
fffffa80bae82870 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae828a0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae828d0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82900 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82930 size: 20 previous size: 30 (Free) None
fffffa80bae82950 size: 30 previous size: 20 (Allocated) hlab
fffffa80bae82980 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae829b0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae829e0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82a10 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82a40 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82a70 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82aa0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82ad0 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82b00 size: 10 previous size: 30 (Free) Scbf
fffffa80bae82b10 size: 30 previous size: 10 (Allocated) hlab
fffffa80bae82b40 size: 30 previous size: 30 (Allocated) hlab
fffffa80bae82b70 size: 10 previous size: 30 (Free) Irp
fffffa80bae82b80 size: 30 previous size: 10 (Allocated) hlab
fffffa80bae82bb0 size: 10 previous size: 30 (Free) TnoC
*fffffa80bae82bc0 size: 440 previous size: 10 (Allocated) *Irp

RBEv and TnoC are tags of my registry driver pools.
mneS is a tag of mine as well.

Thanks,
Daniel

daniel_sela · October 1, 2014, 10:43am

Forgot to mention - I did turn verifier on but that bugcheck came after a long time running smoothly…

Mark_Roddy · October 1, 2014, 2:03pm

On Wed, Oct 1, 2014 at 10:35 AM, wrote:

> The output for dt nt!_IRP fffffa80bae82bd0 is:
> +0x000 Type : 0n13296
> +0x002 Size : 0xba57
>

Those are crap values for an IRP. Type ought to be something like 6 and
size is nowhere near 0xba57.

Mark Roddy

Peter_Scott · October 1, 2014, 2:11pm

As well, while it’s a long shot since verifier should have caught a
buffer overrun when it was freed, I would check the processing of the buffer

fffffa80bae82bb0 size: 10 previous size: 30 (Free) TnoC

to see if there is something going on there.

Pete

On 10/1/2014 12:02 PM, Mark Roddy wrote:

On Wed, Oct 1, 2014 at 10:35 AM, > mailto:xxxxx> wrote:
>
> The output for dt nt!_IRP fffffa80bae82bd0 is:
> +0x000 Type : 0n13296
> +0x002 Size : 0xba57
>
>
> Those are crap values for an IRP. Type ought to be something like 6
> and size is nowhere near 0xba57.
>
> Mark Roddy
> — NTDEV is sponsored by OSR Visit the list at:
> http://www.osronline.com/showlists.cfm?list=ntdev OSR is HIRING!! See
> http://www.osr.com/careers 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

–
Kernel Drivers
Windows File System and Device Driver Consulting
www.KernelDrivers.com
866.263.9295</mailto:xxxxx>

Scott_Noone_OSR · October 1, 2014, 3:14pm

From the dc output it looks like the start of the IRP has been overwritten
by a pointer value:

and the output for dc fffffa80bae82bd0 is:
fffffa80`bae82bd0 ba5733f0 fffffa80 00000000 00000000 .3W…

!pool shows the IRP as still allocated:

fffffa80bae82bb0 size: 10 previous size: 30 (Free) TnoC
*fffffa80bae82bc0 size: 440 previous size: 10 (Allocated) *Irp

So this looks to me like the IRP has been freed to a lookaside list, which
results in memory allocation being turned into a list entry. This is normal
for IRPs, so my guess based on this is that it is a true double IRP complete
and not a corruption.

Why Verifier isn’t whining about anything is a mystery. Daniel, which
drivers did you enable Verifier on?

-scott
OSR
@OSRDrivers

“Mark Roddy” wrote in message news:xxxxx@ntdev…

On Wed, Oct 1, 2014 at 10:35 AM, wrote:

The output for dt nt!_IRP fffffa80bae82bd0 is:
+0x000 Type : 0n13296
+0x002 Size : 0xba57

Those are crap values for an IRP. Type ought to be something like 6 and size
is nowhere near 0xba57.

Mark Roddy

Rudy_Opavsky · October 2, 2014, 12:50am

Can you make sure to enable Special Pool, Pool Tracking, I/O Verification flags (check MSDN)?

Later you can enable verifier for all drivers to see if some other driver is corrupting your IRP.

You can use:

!verifier 0x100

to displays call stacks for IoAllocateIrp, IoCompleteRequest and IoCancelIrp calls for your IRP

!verifier 0x80 to display alloc/free calls for your IRP.

daniel_sela · October 2, 2014, 2:59am

Hey guys,
I turned all of verifier’s checks but low resources.
It currently work for my drivers only - should I add any others? maybe the filter manager?

@Rudy -
I cannot use !verifier yet as I turned it on only after the bugcheck occurred.
If it happens again I will have these and more.

Any other suggestions while waiting for it to reproduce?

Thank you,
Daniel

Rudy_Opavsky · October 2, 2014, 11:43am

I would add other drivers - if you can add all (you can disable advanced checks if your machine gets to sluggish, but keep at least Special Pool, Pool Tracking, I/O Verification and Miscellaneous checks). Memory checks should help if some driver is scribbling on your IRP. If you reproduce it without DV catching anything then try !verifier command to see the call stacks and call history (to check for double completion cases etc.)

daniel_sela · October 6, 2014, 7:50am

Hey,
Adding all of the drivers caused verifier to yell at McAfee’s driver for pool leakage and one more crash of my driver for NULL dereference in an interesting scenario:

I was checking the return value of PsLookupProcessByProcessId using NT_SUCCESS, although the docs clearly mention it can return STATUS_INVALID_PARAMETER which is >= 0, but of-course is not a success code.
In the next line I’m using the OUT param of PsLookupProcessByProcessId which in case of STATUS_INVALID_PARAMETER will not be set correctly and can cause a NULL dereference.

Checking with NT_SUCCESS and not explicitly with STATUS_SUCCESS is something I do in most of my code.
After I discovered this bug I read that developers should use NT_SUCCESS and not explicitly STATUS_SUCCESS, which leaves me confused.

Two questions -

What is the right way to perform these success checks?
Personally I dont see how this can cause such a multiple IRP completion bug check, so I should keep on testing unless someone can see a way these are connected?

Thanks,
Daniel

daniel_sela · October 6, 2014, 8:21am

Reading http://msdn.microsoft.com/en-us/library/windows/hardware/ff565436(v=vs.85).aspx
I found the answer to the first question.

Does anyone think these two crashes can be related?