BSOD: FltGetFileNameInformation

NTFSD
1

Hi,

I’m currently inspecting a mini dump file sent from one of our testers. It comes from WinXP SP2.
The contents of the mini dump are as follows:

kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

KERNEL_MODE_EXCEPTION_NOT_HANDLED_M (1000008e)
This is a very common bugcheck. Usually the exception address pinpoints
the driver/function that caused the problem. Always note this address
as well as the link date of the driver/image that contains this address.
Some common problems are exception code 0x80000003. This means a hard
coded breakpoint or assertion was hit, but this system was booted
/NODEBUG. This is not supposed to happen as developers should never have
hardcoded breakpoints in retail code, but …
If this happens, make sure a debugger gets connected, and the
system is booted /DEBUG. This will let us see why this breakpoint is
happening.
Arguments:
Arg1: c0000006, The exception code that was not handled
Arg2: f82fdb90, The address that the exception occurred at
Arg3: ef75f7d0, Trap Frame
Arg4: 00000000

Debugging Details:

EXCEPTION_CODE: (NTSTATUS) 0xc0000006 - The instruction at “0x%08lx” referenced memory at “0x%08lx”. The required data was not placed into memory because of an I/O error status of “0x%08lx”.

FAULTING_IP:
fltMgr!FltpAllocateInitializeNameGenerationContext+0
f82fdb90 ?? ???

TRAP_FRAME: ef75f7d0 – (.trap 0xffffffffef75f7d0)
ErrCode = 00000010
eax=ef75f880 ebx=00000003 ecx=82055868 edx=82815e44 esi=00000000 edi=8292c420
eip=f82fdb90 esp=ef75f844 ebp=ef75f88c iopl=0 nv up ei pl zr na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010246
fltMgr!FltpAllocateInitializeNameGenerationContext:
f82fdb90 ?? ???
Resetting default scope

CUSTOMER_CRASH_COUNT: 1

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0x8E

PROCESS_NAME: java.exe

LAST_CONTROL_TRANSFER: from f82ee134 to f82fdb90

STACK_TEXT:
ef75f840 f82ee134 ef75f880 82055868 8292c420 fltMgr!FltpAllocateInitializeNameGenerationContext
ef75f88c f8884e7b 82815e44 00000401 ef75f8c0 fltMgr!FltGetFileNameInformation+0xf8
ef75f8c4 f82e9944 82815e44 ef75f8e4 ef75f914 imogenvfs!PreFileOperationCallback+0x5b [d:\winddk\6001.18001\src\filesys\minifilter\scee\imogenvfs\latest\filter\imogenvfskern.c @ 1053]
ef75f924 f82eb352 0075f96c 00000000 ef75f96c fltMgr!FltpPerformPreCallbacks+0x2d4
ef75f938 f82ebc15 ef75f96c 00000000 81df2200 fltMgr!FltpPassThroughInternal+0x32
ef75f954 f82ebffb ef75f901 8292c420 82920898 fltMgr!FltpPassThrough+0x1df
ef75f984 804eeeb1 82057c78 81ee94b0 00016000 fltMgr!FltpDispatch+0xf3
ef75f9a8 804ef8d1 82057c78 820cdd0a 820cdd30 nt!MiAddViewsForSection+0x38
ef75f9c8 8051581e 8292c420 820cdd50 820cdd30 nt!CcAcquireByteRangeForWrite+0x40
ef75f9ec ef75f97c 8209d488 8209d4f8 00000000 nt!RotBarInit+0x55
WARNING: Frame IP not in any known module. Following frames may be wrong.
ef75fa44 8051f347 c07c17e8 f82fdb90 c07c17e8 0xef75f97c
ef75fab0 80543568 00000008 f82fdb90 00000000 nt!MmProbeAndLockPages+0x197
ef75fac8 f82fdb8f badb0d00 824ec534 00000001 nt!VF_ASSERT_IRQL+0x69
ef75fb84 f8884e7b 824ec534 00000401 ef75fbb8 fltMgr!FltGetTunneledName+0x8f
ef75fbbc f82e9944 824ec534 ef75fbdc ef75fc0c imogenvfs!PreFileOperationCallback+0x5b [d:\winddk\6001.18001\src\filesys\minifilter\scee\imogenvfs\latest\filter\imogenvfskern.c @ 1053]
ef75fc1c f82eb352 0075fc64 00000000 ef75fc64 fltMgr!FltpPerformPreCallbacks+0x2d4
ef75fc30 f82ebc15 ef75fc64 00000000 81df2200 fltMgr!FltpPassThroughInternal+0x32
ef75fc4c f82ebffb ef75fc00 81e31d48 82920898 fltMgr!FltpPassThrough+0x1df
ef75fc7c 804eeeb1 82057c78 81f44640 806e4410 fltMgr!FltpDispatch+0xf3
ef75fca0 8057b777 82057c78 81f44640 81f0e810 nt!MiAddViewsForSection+0x38
ef75fd38 8054060c 0000067c 00000000 00000000 nt!MiSetProtectionOnSection+0x2dc
ef75fd64 7c90eb94 badb0d00 02efe858 00000000 nt!RtlIpv4StringToAddressA+0xfd
ef75fd78 00000000 00000000 00000000 00000000 0x7c90eb94

STACK_COMMAND: kb

FOLLOWUP_IP:
imogenvfs!PreFileOperationCallback+5b [d:\winddk\6001.18001\src\filesys\minifilter\scee\imogenvfs\latest\filter\imogenvfskern.c @ 1053]
f8884e7b ?? ???

FAULTING_SOURCE_CODE:
1049: FLT_FILE_NAME_NORMALIZED |
1050: FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP,
1051: &pFileNameInformation );
1052: #if IMOGENVFS_NOT_W2K

1053: if (!NT_SUCCESS(status))
1054: {
1055: // If we couldn’t get the “normalized” name try and get the “opened” name
1056: status = FltGetFileNameInformation( pData,
1057: FLT_FILE_NAME_OPENED |
1058: FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP,

SYMBOL_STACK_INDEX: 2

SYMBOL_NAME: imogenvfs!PreFileOperationCallback+5b

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: imogenvfs

IMAGE_NAME: imogenvfs.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4a0c0b72

FAILURE_BUCKET_ID: 0x8E_imogenvfs!PreFileOperationCallback+5b

BUCKET_ID: 0x8E_imogenvfs!PreFileOperationCallback+5b

Followup: MachineOwner

The offending code is as follows.

FLT_PREOP_CALLBACK_STATUS
PreFileOperationCallback (
__inout PFLT_CALLBACK_DATA pData,
__in PCFLT_RELATED_OBJECTS FltObjects,
__deref_out_opt PVOID *CompletionContext
)
{
NTSTATUS status;
PIVFS_FILE_EVENT pFileEvent = NULL;
PUNICODE_STRING pFilePath = NULL;
PFLT_FILE_NAME_INFORMATION pFileNameInformation = NULL;
HANDLE processId = 0;

// Need to get the process id of the thread that generated this event
if (pData->Thread == NULL)
return FLT_PREOP_SUCCESS_NO_CALLBACK;

if (FLT_IS_FASTIO_OPERATION(pData))
{
// Disallow this open op - it should be reissued as a standard Irp
return FLT_PREOP_DISALLOW_FASTIO;
}

// pick up the filename information
{
// ASSERT(KeGetCurrentIrql() <= APC_LEVEL);
// IRQL: <=APC_LEVEL

>> status = FltGetFileNameInformation( pData,
FLT_FILE_NAME_NORMALIZED |
FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP,
&pFileNameInformation );

Now, the unhandled exception is 0xc0000006 which is STATUS_IN_PAGE_ERROR. i.e. there’s been an attempt at memory read but the data has not be paged in, hence the text.

‘The instruction at “0x%08lx” referenced memory at “0x%08lx”. The required data was not placed into memory because of an I/O error status of “0x%08lx”.’

I’m wondering whether the FltGetFileNameInformation() has been called at the wrong IRQ level to cause this fault? The documentation for FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP says
the following:

‘…and it is currently safe to do so, FltGetFileNameInformation queries the file system…’

Hence I would expect the call to fail gracefully. Should I use be using FLT_FILE_NAME_QUERY_DEFAULT instead?

Looking at the call stack, the PreFileOperationCallback has been re-entered. Perhaps this is what is causing FltpAllocateInitializeNameGenerationContext to fail? Is there any further analysis I could try from the mini dump perspective, to check what might have gone very wrong? Some way of checking what IRQ level a function in the stack was called on perhaps? The local stack data seems reasonable.

pData
Flags 1
Iopb
IrpFlags 0x43
MajorFunction 0x03 Read
MinorFunction 0x00
OperationFlags 0x00
Reserved 0x00
TargetFileObject
Type 5
Size 112
FinalStatus 0
LockOperation 0
DeletePending 0
ReadAccess 1
WriteAccess 1
DeleteAccess 0
SharedRead 0
SharedWrite 1
SharedDelete 0
Flags 0x40008
Filename
Length 0x1x
MaxLength 0x38

My current thoughts are either:

  1. Check for IRQL and avoid FltGetFileNameInformation if > APC_LEVEL
  2. Disallow re-entrancy somehow

Thanks

Mike

2

Hi Mike,

I’m not exactly sure what’s going on, but you should know that FLT_FILE_NAME_INFORMATION structures and most of the functions are paged. So you should not be calling them at IRQL>APC_LEVEL anyway. The documentation for FltGetFileNameInformation states that too.

The “unsafe” state that FltGetFileNameInformation mentions is not so much about IRQL but rather about locks being held in the file system or CC or other components, and in that case it’s not safe to re-enter the file system.

FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP is different from FLT_FILE_NAME_QUERY_DEFAULT in that FLT_FILE_NAME_QUERY_DEFAULT will evaluate if it’s safe to reenter the file system first and then try to get the name from the cache or from the FS, while FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP will try to get the name from the cache first, and only if that fails it will evaluate whether it’s safe to enter the FS and query the name.

The idea is that one should use FLT_FILE_NAME_QUERY_DEFAULT at all times and investigate all failures as they might indicate a design flaw. Using FLT_FILE_NAME_QUERY_ALWAYS_ALLOW_CACHE_LOOKUP could potentially hide those.

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

3

Thanks Alex, I’ll certainly change to using FLT_FILE_NAME_QUERY_DEFAULT, and also add a check for IRQL<=APC_LEVEL.

I’ve searched for FltGetFileNameInformation() within this group, and have been reading a lot of threads to see if I could find anything that might cast light on this issue. The points I’ve come across are:

  1. code seems to perform

if (FltObjects->FileObject != NULL) {

before calling FltGetFileNameInformation().

I’m wondering if this is a requirement? I would have thought not, as it’s not mentioned as part of the FltGetFileNameInformation() documentation.

  1. The note:
    Well, the problem in this case is that FltGetFileNameInformation needs to be
    called at PASSIVE. However, writes don’t always come at passive so calling
    FltGetFileNameInformation directly in your pre-write callback is not always
    possible. The recommended approach is that you take a reference on the
    FILE_OBJECT and queue a work item that gets the file name and sets it in the
    streamhandle context. When you need to use the name, you check if it’s already
    in the streamhandle context or you wait for it (multiple possibilities here, you
    can force your worker thread to pick that work-item up or you ignore all that
    and just read the name right then (and then the work-item will have to deal with
    an already existing name) and so on).

Hmm food for thought there. I’m attempting to call FltGetFileNameInformation regardless of the IRP type.

I’ve made some changes, (irq check and, QUERY_DEFAULT) but I shall have to find a reproducable case for this, to determine whether either change has had any effect.

Cheers
Mike

4

1). Well, if you don’t have a FileObject then of course the question is … what are you querying the name for? It’s not really a requirement as the function takes a CALLBACK_DATA structure and the FileObject comes from there, but depending on the implementation the FileObject is usually the in both.

2). Not sure what exactly you’re trying to implement but querying the name for each operation is not a good idea (and a very big perf hit). Most apps tend to either query the name during create (postCreate preferably) or when they see an operation that is of special interest to them (i.e. on the first write to a file).

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

5

I don’t think this is an IRQL error - if it had been, KiTrap0E would
have done an 0xA bugcheck, not raised an inpage status. I also noted "
ef75fac8 f82fdb8f badb0d00 824ec534 00000001 nt!VF_ASSERT_IRQL+0x69"
which suggests to me that verifier has been called to confirm the IRQL
(but hey, that’s just a guess from context.)

Instead, I would suggest you look in the event log - check and see if
you are getting errors back on that hard drive (remember, you can get an
in-page error when there is a disk problem.) I would have expected a
kernel in-page bug check, but Mm does report errors of this type for
some operations. It’s ALSO possible your filter is interfering with the
read operation and that could ALSO cause the in page error (this
recursion shown on the stack is intriguing.)

It’s an interesting stack trace. But it’s a memory dump so you can’t do
much.

One other hint: tell your testers to stop slacking and collect kernel
summary dumps. Mini-dumps just don’t give you enough to do anything
useful.

Tony
OSR

6

I said:

“But it’s a memory dump so you can’t do much.”

But it should say:

“But it’s a mini dump so you can’t do much.”

Tony
OSR

7

Hi,

Thanks for your comments. Here’s a bit of background info:

The mini filter is performing file re-direction. It re-directs create ops which occur on a specified source directory tree, over to a target directory tree. It also attempts to track all file ops within that specified source directory tree, hence the requirement to get the filename information.

It does this by generating a new

pData->Iopb->TargetFileObject

either by overwrite, if the UNICODE buffer is large enough, or by re-allocating the buffer.
It re-issues the op via setting:

pData->IoStatus.Status = STATUS_REPARSE;
pData->IoStatus.Information = IO_REPARSE;
pData->Iopb->TargetFileObject->RelatedFileObject = NULL;
FltSetCallbackDataDirty( pData );

So, this *could* potentially suggest a reason why the PreFileOp is being called twice (i.e. by way of re-parse). However the re-mapping code is only ever called for IRP_MJ_CREATE, and it is called some time after the call to FltGetFileNameInformation(), which suggests it has not been involved in the execution thread of the presented stack.

I’ll limit the mini filter to the following:

IRP_MJ_CREATE
IRP_MJ_CREATE_NAMED_PIPE
IRP_MJ_CLOSE
IRP_MJ_READ
IRP_MJ_WRITE

and see whether we can get away with that for tracking. It may be we can drop the need to track read/write too.

I’ll try to get hold of kernel summary dumps to get more information on the crash. My guess is its certainly something the mini-filter is doing to cause this problem.

Mike

8

VF_ASSERT_IRQL/MmProbeAndLockPages/RotBarInit are not related, so probably the kernel symbols were incorrect (unless the kernel stack was corrupted).

Dan

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Tony Mason
Sent: Wednesday, June 10, 2009 9:13 PM
To: Windows File Systems Devs Interest List
Subject: RE: [ntfsd] BSOD: FltGetFileNameInformation

I don’t think this is an IRQL error - if it had been, KiTrap0E would
have done an 0xA bugcheck, not raised an inpage status. I also noted "
ef75fac8 f82fdb8f badb0d00 824ec534 00000001 nt!VF_ASSERT_IRQL+0x69"
which suggests to me that verifier has been called to confirm the IRQL
(but hey, that’s just a guess from context.)

Instead, I would suggest you look in the event log - check and see if
you are getting errors back on that hard drive (remember, you can get an
in-page error when there is a disk problem.) I would have expected a
kernel in-page bug check, but Mm does report errors of this type for
some operations. It’s ALSO possible your filter is interfering with the
read operation and that could ALSO cause the in page error (this
recursion shown on the stack is intriguing.)

It’s an interesting stack trace. But it’s a memory dump so you can’t do
much.

One other hint: tell your testers to stop slacking and collect kernel
summary dumps. Mini-dumps just don’t give you enough to do anything
useful.

Tony
OSR

NTFSD is sponsored by OSR

For our schedule of debugging and file system seminars
(including our new fs mini-filter seminar) 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