IRP_MJ_CLOSE called twice for a FileObject...

NTFSD
1

How and when IoManager generates more than one IRP_MJ_CLOSE per file
object?

I found that this happens in my file system driver. After processing the
first request in my close dispatch routine (free FCB, CCB and etc.), I
receive second close on the same FileObject. In second call I do just
nothing - just completing the Irp and bugcheck occurs ( whithout our FS
driver in the stack ).

May be I am wrong, but as I know, IRP_MJ_CLOSE must be generated once,
when refence count to the specific fileobject goes to zero!?

Here is a bug check :

BAD_POOL_CALLER (c2)
The current thread is making a bad pool request. Typically this is at a
bad IRQL level or double freeing the same allocation, etc.
Arguments:
Arg1: 00000007, Attempt to free pool which was already freed
Arg2: 00000c3e, (reserved)
Arg3: 00080204, Memory contents of the pool block
Arg4: e1c084b8, Address of the block of pool being deallocated

Debugging Details:

FREED_POOL_TAG: IoNm

BUGCHECK_STR: 0xc2_7_IoNm

DEFAULT_BUCKET_ID: DRIVER_FAULT

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
f8c7c75c 805258ca 00000003 f8c7ca8c 00000007
nt!RtlpBreakWithStatusInstruction
f8c7c7a8 80526160 00000003 e1c084b0 e1c084b8 nt!KiBugCheckDebugBreak+0x19
f8c7cb74 805266db 000000c2 00000007 00000c3e nt!KeBugCheck2+0x46d
f8c7cb94 8053d4a1 000000c2 00000007 00000c3e nt!KeBugCheckEx+0x19
f8c7cbdc 805870ee e1c084b8 00000000 8186f428 nt!ExFreePoolWithTag+0x237
f8c7cc1c 8057e49d 0086f440 8186f428 00000000 nt!IopDeleteFile+0x1a5
f8c7cc38 804ecc07 8186f440 00000000 00000000
nt!ObpRemoveObjectRoutine+0xdd
f8c7cc5c 805831dc f8c7cd64 0199f89c 80585233 nt!ObfDereferenceObject+0x5d
f8c7ccbc 8058324e 0199f8f0 010e0000 0199f8a8 nt!IopCreateFile+0x534
f8c7cd04 80585258 0199f8f0 010e0000 0199f8a8 nt!IoCreateFile+0x36
f8c7cd44 804da140 0199f8f0 010e0000 0199f8a8 nt!NtOpenFile+0x25
f8c7cd44 7ffe0304 0199f8f0 010e0000 0199f8a8 nt!KiSystemService+0xc4
0199f878 77f75e07 5d68336a 0199f8f0 010e0000
SharedUserData!SystemCallStub+0x4
0199f87c 5d68336a 0199f8f0 010e0000 0199f8a8 ntdll!ZwOpenFile+0xc
0199f8e8 5d682640 00000000 00000000 00000000 rshx32!CheckFileAccess+0xa3
0199fb40 5d6829a4 000e11f0 00132040 0011ea60
rshx32!CRShellExt::CheckForSecurity+0x198
0199fb50 5d682adf 0011ea60 00132040 0199fc5c
rshx32!CRShellExt::DoSecurityCheck+0x2f
0199fb8c 774a7c5b 0011ea64 774a7bc0 0199fc5c
rshx32!CRShellExt::AddPages+0x9f
0199fbb4 774a8038 00120ca0 00000592 0011ea60
SHELL32!DCA_AppendClassSheetInfo+0x76
0199fcd0 774ef9cb 00100c80 0199ff08 00000005
SHELL32!SHOpenPropSheetW+0x12f
0199ff3c 774bc1d7 0012f780 00000000 00000000
SHELL32!CFSFolder::_PropertiesThread+0x89
0199ff50 70a7df5f 000cc7e0 00000000 00dddc08
SHELL32!_PropSheetThreadProc+0x15
0199ffb4 77e7d33b 00000000 00000000 00dddc08
SHLWAPI!WrapperThreadProc+0x92
0199ffec 00000000 70a7def2 00dddff4 00000000 kernel32!BaseThreadStart+0x37

FOLLOWUP_IP:
nt!KiBugCheckDebugBreak+19
805258ca eb59 jmp nt!KiBugCheckDebugBreak+0x74 (80525925)

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: nt!KiBugCheckDebugBreak+19

MODULE_NAME: nt

IMAGE_NAME: ntoskrnl.exe

DEBUG_FLR_IMAGE_TIMESTAMP: 3d6de35c

STACK_COMMAND: kb

BUCKET_ID: 0xc2_7_IoNm_nt!KiBugCheckDebugBreak+19

2

A filter may see closes for file objects it did not see a corresponding
create for - (stream file objects used internally by the FSD) - but an
FSD should not.

Kristian Traikov wrote:

How and when IoManager generates more than one IRP_MJ_CLOSE per file
object?

I found that this happens in my file system driver. After processing the
first request in my close dispatch routine (free FCB, CCB and etc.), I
receive second close on the same FileObject. In second call I do just
nothing - just completing the Irp and bugcheck occurs ( whithout our FS
driver in the stack ).

May be I am wrong, but as I know, IRP_MJ_CLOSE must be generated once,
when refence count to the specific fileobject goes to zero!?

Here is a bug check :

BAD_POOL_CALLER (c2)
The current thread is making a bad pool request. Typically this is at a
bad IRQL level or double freeing the same allocation, etc.
Arguments:
Arg1: 00000007, Attempt to free pool which was already freed
Arg2: 00000c3e, (reserved)
Arg3: 00080204, Memory contents of the pool block
Arg4: e1c084b8, Address of the block of pool being deallocated

Debugging Details:

FREED_POOL_TAG: IoNm

BUGCHECK_STR: 0xc2_7_IoNm

DEFAULT_BUCKET_ID: DRIVER_FAULT

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
f8c7c75c 805258ca 00000003 f8c7ca8c 00000007
nt!RtlpBreakWithStatusInstruction
f8c7c7a8 80526160 00000003 e1c084b0 e1c084b8 nt!KiBugCheckDebugBreak+0x19
f8c7cb74 805266db 000000c2 00000007 00000c3e nt!KeBugCheck2+0x46d
f8c7cb94 8053d4a1 000000c2 00000007 00000c3e nt!KeBugCheckEx+0x19
f8c7cbdc 805870ee e1c084b8 00000000 8186f428 nt!ExFreePoolWithTag+0x237
f8c7cc1c 8057e49d 0086f440 8186f428 00000000 nt!IopDeleteFile+0x1a5
f8c7cc38 804ecc07 8186f440 00000000 00000000
nt!ObpRemoveObjectRoutine+0xdd
f8c7cc5c 805831dc f8c7cd64 0199f89c 80585233 nt!ObfDereferenceObject+0x5d
f8c7ccbc 8058324e 0199f8f0 010e0000 0199f8a8 nt!IopCreateFile+0x534
f8c7cd04 80585258 0199f8f0 010e0000 0199f8a8 nt!IoCreateFile+0x36
f8c7cd44 804da140 0199f8f0 010e0000 0199f8a8 nt!NtOpenFile+0x25
f8c7cd44 7ffe0304 0199f8f0 010e0000 0199f8a8 nt!KiSystemService+0xc4
0199f878 77f75e07 5d68336a 0199f8f0 010e0000
SharedUserData!SystemCallStub+0x4
0199f87c 5d68336a 0199f8f0 010e0000 0199f8a8 ntdll!ZwOpenFile+0xc
0199f8e8 5d682640 00000000 00000000 00000000 rshx32!CheckFileAccess+0xa3
0199fb40 5d6829a4 000e11f0 00132040 0011ea60
rshx32!CRShellExt::CheckForSecurity+0x198
0199fb50 5d682adf 0011ea60 00132040 0199fc5c
rshx32!CRShellExt::DoSecurityCheck+0x2f
0199fb8c 774a7c5b 0011ea64 774a7bc0 0199fc5c
rshx32!CRShellExt::AddPages+0x9f
0199fbb4 774a8038 00120ca0 00000592 0011ea60
SHELL32!DCA_AppendClassSheetInfo+0x76
0199fcd0 774ef9cb 00100c80 0199ff08 00000005
SHELL32!SHOpenPropSheetW+0x12f
0199ff3c 774bc1d7 0012f780 00000000 00000000
SHELL32!CFSFolder::_PropertiesThread+0x89
0199ff50 70a7df5f 000cc7e0 00000000 00dddc08
SHELL32!_PropSheetThreadProc+0x15
0199ffb4 77e7d33b 00000000 00000000 00dddc08
SHLWAPI!WrapperThreadProc+0x92
0199ffec 00000000 70a7def2 00dddff4 00000000 kernel32!BaseThreadStart+0x37

FOLLOWUP_IP:
nt!KiBugCheckDebugBreak+19
805258ca eb59 jmp nt!KiBugCheckDebugBreak+0x74 (80525925)

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: nt!KiBugCheckDebugBreak+19

MODULE_NAME: nt

IMAGE_NAME: ntoskrnl.exe

DEBUG_FLR_IMAGE_TIMESTAMP: 3d6de35c

STACK_COMMAND: kb

BUCKET_ID: 0xc2_7_IoNm_nt!KiBugCheckDebugBreak+19

–
Nick Ryan (MVP for DDK)

3

Thanks for your answer Nick.

Anyway I found the problem - it was a bug in my IRP_MJ_CLEANUP routine. I
had call to the ObReferenceObject() and ObDereferenceObject() for the
FileObject.

Sometimes current FileObject reference count was ZERO (in cleanup dispatch
routine - I don’t know if this is a normal behaviour?!) and my additional
Reference/Dereference causes an additional IRP_MJ_CLOSE…

Now, I still have some questions:

  1. Is this normal that FileObject reference count is ZERO in CLEANUP
    dispatch routine?

  2. Is this normal that FileObject reference count is NOT ZERO in CLOSE
    dispatch routine?

Thanks,
Kristian