MULTIPLE_IRP_COMPLETE_REQUESTS

Hello Gurus,

I am terribly stuck with this bug.
I am getting this bug in my Filter Driver. The Debugger says that the
driver which completed the IRP Packet is ntoskrnl.exe .
The last comments which I see are as highlighted in Red described below
in Pseudo code .
So I completed the IRP meant for ntoskrnl.exe. But this Bug is only when
I open a Heavy WebPage in Internet explorer that is : some activity
which requires heavy CREAT Processing with Asynchronous threads .
Point to be noted is I seen this Dbgprint of IRP completion many a
times before the crash i.e. It produced no crash when my driver
completed the packet may a times before .
I have read if returning STATUS_MORE_PROCESSING_REQUIRED in completion
routine , we should either return status pending with marking IRP
Pending or I should make the routine Synchronous.
Can this problem be solved buy making the routine Synchronous ?.
Can you guide me if my flow as described below in Pseudo code is correct
? .
What can be the cause of this bug in my flow .
I can provide you the crash dump details .
Any suggestions ??
Regards,
Anurag



CREAT Dispatch Routine

Control for filter :
Call SpyPassThrough Routine // as shown below

ntStatus =
KeWaitForSingleObject(&kEvent,Executive,KernelMode,FALSE,NULL);

if(ntStatus == STATUS_SUCCESS )
{
irpStack = IoGetCurrentIrpStackLocation( Irp );
Get File name from irpStack and File Object and Store in
Unicode String
If one of Registry files
{
Acquire Spinlock
Search if file is in Registry link list.
If file exist in link list
{
Release Spin Lock
Irp->IoStatus.Information = IO_REPARSE;
IoCompleteRequest(Irp,IO_NO_INCREMENT);
return STATUS_REPARSE;
}
}
Release Spin Lock

If File is one from My Buffer
{
DbgPrint(“\nCR5:Before Completing IRP:%x”,Irp);
IoCompleteRequest(Irp,IO_NO_INCREMENT);
DbgPrint(“\nCR5:After Completing IRP:%x”,Irp);
ntStatus = Irp->IoStatus.Status;
return ntStatus;
}
If Create Link List is empty // inserting first element
{
Add the file name in Link List using Spin Locks
If file is one of my files, log files using ZWCreate Function

DbgPrint(“\nCR4:Before Completing IRP:%x”,Irp);
IoCompleteRequest(Irp,IO_NO_INCREMENT);
DbgPrint(“\nCR4:After Completing IRP:%x”,Irp);
ntStatus = Irp->IoStatus.Status;
return ntStatus;
}
Acquire Spin Lock
If Create Link List has elements
{
If this filename found in Create Link List
{
KeReleaseSpinLock(&CreateListSpinLock,OldIrql);

DbgPrint(“\nCR3:Before Completing IRP:%x”,Irp);
IoCompleteRequest(Irp,IO_NO_INCREMENT);
DbgPrint(“\nCR3:After Completing IRP:%x”,Irp);
ntStatus = Irp->IoStatus.Status;
return ntStatus;
}
}
KeReleaseSpinLock(&CreateListSpinLock,OldIrql);

//Since failed in above conditions
Insert Filename in Link List Using Spin Locks
If file is one of my files
{
log files using ZWCreate Function
DbgPrint(“\nCR2:Before Completing IRP:%x”,Irp);
IoCompleteRequest(Irp,IO_NO_INCREMENT);
DbgPrint(“\nCR2:After Completing IRP:%x”,Irp);
ntStatus = Irp->IoStatus.Status;
return ntStatus;
}

DbgPrint(“\nCR1:Before Completing IRP:%x”,Irp);
IoCompleteRequest(Irp,IO_NO_INCREMENT);
DbgPrint(“\nCR1:After Completing IRP:%x”,Irp);
ntStatus = Irp->IoStatus.Status;
return ntStatus;
}
return ntStatus;



-------------------SpyPasThrough Routine---------------------
IoCopyCurrentIrpStackLocationToNext( Irp );

IoSetCompletionRoutine(Irp,MyCompletionToWait,pContext,TRUE,TRUE,TRUE);
status = IoCallDriver(
((PFILESPY_DEVICE_EXTENSION)DeviceObject->DeviceExtension)->AttachedToDe
viceObject, Irp ); return status;

--------Completion Routine : MyCompletionToWait

KeSetEvent(pkEvent,0,FALSE );
DbgPrint(“\nMyCompletionToWait End”);
return STATUS_MORE_PROCESSING_REQUIRED;

I have now changed my flow from returning MORE_PROCESSING_REQUIRED to as
passing IRP to lower driver and returning STATUS_SUCCESS in comlpetion
routine.

But the problem remains the same.

I mainly have two dispatch routines CREAT and WRITE . I guess problem is
in my CREAT Routine.

As the article explains they show code of passing the IRP to lower
driver as mentioned in SpyPassThrough Routine below called only once but
I am calling that many times as per my demand. Flow in Create routine
remains highly Asyncronous so is calling SpyPassThrough into many if
else statements making a problem that I am sending down IRPs wrongly ?.

------------------------------------------------x-----------------------

CREAT Dispatch Routine

Control for filter :

irpStack = IoGetCurrentIrpStackLocation( Irp );

Get File name from irpStack and File Object and Store in Unicode String

If one of Registry files

{

Acquire Spinlock

Search if file is in Registry link list.

If file exist in link list

{

Release Spin Lock

Irp->IoStatus.Status = STATUS_REPARSE;

Irp->IoStatus.Information = IO_REPARSE;

return STATUS_REPARSE;

}

}

Release Spin Lock

If File is one from My Buffer

{

Return SpyPassthrough

}

If Create Link List is empty

{

Add the file name in Link List using Spin Locks

If file is one of my files, log files using ZWCreate Function

Return SpyPassthrough

}

Acquire Spin Lock

If Create Link List has elements

{

If this filename found in Create Link List

{

KeReleaseSpinLock(&CreateListSpinLock,OldIrql);

Return SpyPassthrough

}

}

KeReleaseSpinLock(&CreateListSpinLock,OldIrql);

Insert Filename in Link List Using Spin Locks

If file is one of my files

{

log files using ZWCreate Function

Return SpyPassthrough

}

Return SpyPassthrough

------------------------------------------------x-----------------------

-------------------SpyPasThrough Routine---------------------

ASSERT(IS_FILESPY_DEVICE_OBJECT( DeviceObject ));

DbgPrint(“\nPT:IRP before copying stack location IRP:%x”,Irp);

IoCopyCurrentIrpStackLocationToNext( Irp );

IoSetCompletionRoutine( Irp,

MyCompletion,

NULL,

TRUE,

TRUE,

TRUE);

DbgPrint(“\nPT:Before Sending Down IRP:%x”,Irp);

status = IoCallDriver(
((PFILESPY_DEVICE_EXTENSION)DeviceObject->DeviceExtension)->AttachedToDe
viceObject, Irp );

DbgPrint(“\nPT:After Sending Down IRP:%x”,Irp);

return status;

----------------------------------xx--------------------------------

--------Completion Routine : MyCompletionToWait

if (Irp->PendingReturned)

{

DbgPrint(“\nMC:Marking IRP Pending”);

IoMarkIrpPending( Irp );

}

return STATUS_SUCCESS;

---------------------------------x--------------------------------------

Regards,

Anurag

> I tried to trace the IRP values as shown in the SpyPassThrough

routine these are the latest comments before the crash.

***************************************************
CR:Entry present in Create link list So no logging
MC:Freeing Memory compare_c.Buffer
MC:Freeing Memory fullFileName_New.Buffer
PT:IRP before copying stack location IRP:814c0b28
PT:Before Sending Down IRP:814c0b28
PT:IRP before copying stack location IRP:814c0ce8
PT:After Sending Down IRP:814c0b28
PT:IRP before copying stack location IRP:814c0b28
PT:Before Sending Down IRP:814c0b28
PT:Before Sending Down IRP:814c0ce8
PT:After Sending Down IRP:814c0b28
PT:IRP before copying stack location IRP:814c0b28
PT:Before Sending Down IRP:814c0b28
PT:After Sending Down IRP:814c0b28
PT:IRP before copying stack location IRP:814c0b28
PT:Before Sending Down IRP:814c0b28
PT:After Sending Down IRP:814c0b28
PT:After Sending Down IRP:814c0ce8
*** Fatal System Error: 0x00000044
(0x814C0CE8,0x00001A11,0x00000000,0x00000000)

Arg1: 814c0ce8, Address of the IRP
Arg2: 00001a11
Arg3: 00000000
Arg4: 00000000

Debugging Details:

IRP_ADDRESS: 814c0ce8

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0x44

LAST_CONTROL_TRANSFER: from 8042bcb9 to 80452e70

STACK_TEXT:
ed18f540 8042bcb9 00000003 ed18f588 814c0ce8
nt!RtlpBreakWithStatusInstruction
ed18f570 8042c068 00000003 00000000 814c0ce8
nt!KiBugCheckDebugBreak+0x31
ed18f8f8 8041fdd4 00000000 814c0ce8 00001a11 nt!KeBugCheckEx+0x37b
ed18f920 8041fdb0 814c0ce8 804a3eb6 814c0ce8 nt!IopFreeIrp+0x20
ed18f928 804a3eb6 814c0ce8 804a392a 8184c018 nt!IoFreeIrp+0xa
ed18fab4 8044e27e 8184c030 00000000 ed18fb60 nt!IopParseDevice+0xa95
ed18fb20 804957ae 00000000 ed18fc00 00000040
nt!ObpLookupObjectName+0x4c4
ed18fc30 804a78b8 00000000 00000000 8044c001
nt!ObOpenObjectByName+0xc5
ed18fd04 804a361e 000676f4 00100001 000676c0 nt!IoCreateFile+0x3ec
ed18fd44 80461691 000676f4 00100001 000676c0 nt!NtOpenFile+0x25
ed18fd44 77f8b5bf 000676f4 00100001 000676c0 nt!KiSystemService+0xc4
00067674 77e9aaa6 000676f4 00100001 000676c0 ntdll!NtOpenFile+0xb
000676ec 77e85241 00000000 00067860 00067858
KERNEL32!GetDiskFreeSpaceExW+0x79
00067704 76c0654e 00087db8 00067860 00067858
KERNEL32!GetDiskFreeSpaceExA+0x2d
00067878 76c06a49 00087db8 00087d6c 000679a4
WININET!GetDiskInfoA+0x186
000679b8 76c02425 00067a8c 000a5ee0 000679e8
WININET!URL_CONTAINER::Init+0x127
000679cc 76c05296 00000004 00000014 00000000
WININET!CConMgr::FindIndexFromPrefix+0x8a
000679e8 76c09fa4 00067a8c 00067a14 00067a5c
WININET!CConMgr::FindNextEntry+0x81
00067a60 76c0a330 00067a8c 00067ae8 00000001
WININET!FindUrlCacheEntryWCore+0xc4
00067a90 76c0a305 00067ae8 00000001 00300035
WININET!FindFirstUrlCacheEntryExW+0x28
00067abc 76d10c85 00067ae8 000b6b50 00067b6c
WININET!FindFirstUrlCacheEntryW+0x1f
00067acc 76d1421e 00067ae8 000b6b50 00067b6c
shdocvw!FindFirstUrlCacheEntryW+0x34
00067b7c 76cb9ada 000b16ac 00000001 000b6440
shdocvw!CHistCacheFolder::_CopyEntries+0x71
00067ba0 76c84989 cbac4000 01c48bc8 1d74c000
shdocvw!CHistCacheFolder::_CleanUpHistory+0x92
00067c44 76c846e5 00082a9c 00067ca8 76c8437f
shdocvw!CHistCacheFolder::_ValidateIntervalCache+0x38c
00067c50 76c8437f 000b6450 00068d1c 1302bee7
shdocvw!CHistCacheFolder::WriteHistory+0x11
00067ca8 76c83a21 00068d1c 0006a390 00082a9c
shdocvw!CUrlHistory::_WriteToHistory+0x61
0006a3c4 76c9438a 000aa998 0006c420 0006d484
shdocvw!CUrlHistory::AddUrlAndNotifyCP+0x282
0006a3f0 76c93a9a 0006c420 0006d484 000aa998
shdocvw!AddUrlToUrlHistoryStg+0x61
0006d470 76c937c5 0006d484 0006d6d8 76c8cd20
shdocvw!CDocObjectHost::_UpdateHistoryAndIntSiteDB+0xab
0006d690 76c983eb 00082714 00000001 ffffffff
shdocvw!CDocObjectHost::_OnReadyState+0xe8
0006d6ec 76c98370 75b019a5 00097dd4 fffffdf3
shdocvw!CDocObjectHost::_OnChangedReadyState+0x7c
0006d6f0 75b019a5 00097dd4 fffffdf3 000a7dd0
shdocvw!CDocObjectHost::OnChanged+0x21
0006d728 75b663fc fffffdf3 00000001 000a7dd0
mshtml!CBase::FirePropertyNotify+0x93
0006d738 75b5c398 00000004 000a7dd0 00f80610
mshtml!CDoc::SetReadyState+0x50
0006d798 75b5c72b 00000004 00f81420 00000000
mshtml!CDoc::OnLoadStatus+0x8b
0006d7e0 75b5ba76 00000004 0006dc44 00f95d24
mshtml!CMarkup::OnLoadStatus+0x5b
0006dc1c 75af3804 00f81420 00f81420 00008002
mshtml!CProgSink::OnMethodCall+0x406
0006dc50 75af1997 0006dd58 0006dd60 c0000000
mshtml!GlobalWndOnMethodCall+0x63
0006dc70 77e13eb0 0001018a 0000006a 00000000 mshtml!GlobalWndProc+0xa4
0006dc90 77e1401a 75af18e8 0001018a 00008002
USER32!UserCallWinProc+0x18
0006dd1c 77e13f0f 0006dd58 00000000 76e2468f
USER32!DispatchMessageWorker+0x2d0
0006dd28 76e2468f 0006dd58 00000000 0007a468
USER32!DispatchMessageW+0xb
0006dd40 76e32d09 0006dd58 0006ee88 0007a278
BROWSEUI!TimedDispatchMessage+0x35
0006dd8c 76e32af4 0006014a 0006ee88 0007a278
BROWSEUI!BrowserThreadProc+0x240
0006de14 76e2c550 0007a278 00000001 0007a278
BROWSEUI!BrowserProtectedThreadProc+0xa1
0006ee90 76ca7bb4 0007a278 76ca7935 0007a278
BROWSEUI!SHOpenFolderWindow+0x209
0006ee98 76ca7935 0007a278 00000001 00000000
shdocvw!SHOpenFolderWindow+0x29
0006ff00 004013b6 000728f1 00000001 00401a46 shdocvw!IEWinMain+0x101
0006ff0c 00401a46 000728f1 00000001 00740070 iexplore!IEWinMain+0x4a

FOLLOWUP_IP:
nt!IopParseDevice+a95
804a3eb6 8a8d24ffffff mov cl,[ebp-0xdc]

SYMBOL_STACK_INDEX: 5

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: nt!IopParseDevice+a95

MODULE_NAME: nt

IMAGE_NAME: ntoskrnl.exe

DEBUG_FLR_IMAGE_TIMESTAMP: 384d9b17

STACK_COMMAND: kb

BUCKET_ID: 0x44_nt!IopParseDevice+a95

Followup: MachineOwner

***************************************************

Please help me get out of the trouble.
Regards,
Anurag