PAGE_FAULT_IN_NONPAGED_AREA - ntfs.sys - writing data to sparse file

Lars_Diehl · March 26, 2018, 3:43am

Hi all,
we received a couple of crashes like the following from one of our customers:

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

PAGE_FAULT_IN_NONPAGED_AREA (50)
Invalid system memory was referenced. This cannot be protected by try-except.
Typically the address is just plain bad or it is pointing at freed memory.
Arguments:
Arg1: fffff88007d10038, memory referenced.
Arg2: 0000000000000000, value 0 = read operation, 1 = write operation.
Arg3: fffff88001627ec0, If non-zero, the instruction address which referenced the bad memory
address.
Arg4: 0000000000000000, (reserved)

Debugging Details:

DUMP_CLASS: 1

DUMP_QUALIFIER: 402

BUILD_VERSION_STRING: 7601.23915.amd64fre.win7sp1_ldr.170913-0600

SYSTEM_MANUFACTURER: VMware, Inc.

VIRTUAL_MACHINE: VMware

SYSTEM_PRODUCT_NAME: VMware Virtual Platform

SYSTEM_VERSION: None

BIOS_VENDOR: Phoenix Technologies LTD

BIOS_VERSION: 6.00

BIOS_DATE: 09/21/2015

BASEBOARD_MANUFACTURER: Intel Corporation

BASEBOARD_PRODUCT: 440BX Desktop Reference Platform

BASEBOARD_VERSION: None

DUMP_TYPE: 0

BUGCHECK_P1: fffff88007d10038

BUGCHECK_P2: 0

BUGCHECK_P3: fffff88001627ec0

BUGCHECK_P4: 0

READ_ADDRESS: fffff88007d10038

FAULTING_IP:
Ntfs!memcpy+250
fffff880`01627ec0 488b440af8 mov rax,qword ptr [rdx+rcx-8]

MM_INTERNAL_CODE: 0

IMAGE_NAME: Ntfs.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 59e5328e

MODULE_NAME: Ntfs

FAULTING_MODULE: fffff88001619000 Ntfs

CPU_COUNT: 4

CPU_MHZ: 898

CPU_VENDOR: GenuineIntel

CPU_FAMILY: 6

CPU_MODEL: 2d

CPU_STEPPING: 7

CPU_MICROCODE: 6,2d,7,0 (F,M,S,R) SIG: 710’00000000 (cache) 710’00000000 (init)

DEFAULT_BUCKET_ID: WIN7_DRIVER_FAULT

BUGCHECK_STR: 0x50

PROCESS_NAME: System

CURRENT_IRQL: 0

ANALYSIS_SESSION_HOST: VM-DGDEV

ANALYSIS_SESSION_TIME: 03-25-2018 16:02:52.0602

ANALYSIS_VERSION: 10.0.14321.1024 x86fre

TRAP_FRAME: fffff88001fdc280 – (.trap 0xfffff88001fdc280)
NOTE: The trap frame does not contain all registers.
Some register values may be zeroed or incorrect.
rax=fffff88007d0f040 rbx=0000000000000000 rcx=fffffa80070db800
rdx=fffffe0000c34840 rsi=0000000000000000 rdi=0000000000000000
rip=fffff88001627ec0 rsp=fffff88001fdc418 rbp=0000000000000800
r8=0000000000000800 r9=0000000000000040 r10=0000000000000000
r11=fffffa80070db000 r12=0000000000000000 r13=0000000000000000
r14=0000000000000000 r15=0000000000000000
iopl=0 nv up ei ng nz na pe cy
Ntfs!memcpy+0x250:
fffff88001627ec0 488b440af8 mov rax,qword ptr [rdx+rcx-8] ds:fffff88007d10038=???
Resetting default scope

BAD_STACK_POINTER: fffff88001fdc118

LAST_CONTROL_TRANSFER: from fffff8000194770e to fffff800018cae00

STACK_TEXT:
fffff88001fdc118 fffff8000194770e : 0000000000000050 fffff88007d10038 0000000000000000 fffff88001fdc280 : nt!KeBugCheckEx
fffff88001fdc120 fffff800018c8f2e : 0000000000000000 fffff88007d10038 0000000000000000 0000000000000000 : nt! ?? ::FNODOBFM::string'+0x3bdaf fffff88001fdc280 fffff88001627ec0 : fffff88001648810 fffffa8007b43cc0 fffff88000000000 0000000000000001 : nt!KiPageFault+0x16e fffff88001fdc418 fffff88001648810 : fffffa8007b43cc0 fffff88000000000 0000000000000001 0000000000000800 : Ntfs!memcpy+0x250 fffff88001fdc420 fffff880016494d5 : fffff88001fdc780 fffff88001fdc5b8 0000000000000000 fffffa800e8fa010 : Ntfs!NtfsCopyFromMdl+0x18d fffff88001fdc500 fffff88001622ef5 : fffff8a0192bd820 fffffa800e8fa000 0000000000000000 0000000000010000 : Ntfs!NtfsPrepareSparseWriteBuffer+0x85 fffff88001fdc550 fffff8800162d8a9 : fffffa80076d6e40 fffffa800e8fa010 fffff8a0192bd820 0000000000020000 : Ntfs!NtfsPrepareComplexBuffers+0x295 fffff88001fdc6b0 fffff8800162cdf0 : fffff8a0192bd820 0000000000000000 fffff88001fdc7d0 000000000001f800 : Ntfs!NtfsPrepareBuffers+0x179 fffff88001fdc730 fffff88001630f13 : fffffa80076d6e40 fffffa800e8fa010 0000000000000000 fffff880016a5b00 : Ntfs!NtfsNonCachedIo+0x310 fffff88001fdc8f0 fffff8800161c25b : fffffa80076d6e40 fffffa800e8fa010 fffff8a0c0000000 fffffa8000001000 : Ntfs!NtfsCommonWrite+0x2f64 fffff88001fdcaa0 fffff800018d5085 : 0000000000000000 fffff88005f3f300 0000000000000000 fffffa8000000000 : Ntfs!NtfsFspDispatch+0x28b fffff88001fdcb70 fffff80001b65622 : 0000000000000000 fffffa8006d1e040 0000000000000080 fffffa8006cae970 : nt!ExpWorkerThread+0x111 fffff88001fdcc00 fffff800018bcda6 : fffff88001ee1180 fffffa8006d1e040 fffffa8006d1f660 0000000000000000 : nt!PspSystemThreadStartup+0x5a fffff88001fdcc40 0000000000000000 : fffff88001fdd000 fffff88001fd7000 fffff88001fdc440 00000000`00000000 : nt!KiStartSystemThread+0x16

STACK_COMMAND: kb

THREAD_SHA1_HASH_MOD_FUNC: f38074d07ad66b3f9e2d5388223fbbf4ddbaa89e

THREAD_SHA1_HASH_MOD_FUNC_OFFSET: 7c81de6a78e22f1151cfac9128d2288523a00810

THREAD_SHA1_HASH_MOD: e6d638e2379ef50d39ad6a7d17a2cb0ca1708701

FOLLOWUP_IP:
Ntfs!memcpy+250
fffff880`01627ec0 488b440af8 mov rax,qword ptr [rdx+rcx-8]

FAULT_INSTR_CODE: a448b48

SYMBOL_STACK_INDEX: 3

SYMBOL_NAME: Ntfs!memcpy+250

FOLLOWUP_NAME: MachineOwner

IMAGE_VERSION: 6.1.7601.23932

FAILURE_BUCKET_ID: X64_0x50_STACKPTR_ERROR_Ntfs!memcpy+250

BUCKET_ID: X64_0x50_STACKPTR_ERROR_Ntfs!memcpy+250

PRIMARY_PROBLEM_CLASS: X64_0x50_STACKPTR_ERROR_Ntfs!memcpy+250

TARGET_TIME: 2018-03-13T06:23:16.000Z

OSBUILD: 7601

OSSERVICEPACK: 1000

SERVICEPACK_NUMBER: 0

OS_REVISION: 0

SUITE_MASK: 272

PRODUCT_TYPE: 3

OSPLATFORM_TYPE: x64

OSNAME: Windows 7

OSEDITION: Windows 7 Server (Service Pack 1) TerminalServer SingleUserTS

OS_LOCALE:

USER_LCID: 0

OSBUILD_TIMESTAMP: 2017-09-13 16:55:13

BUILDDATESTAMP_STR: 170913-0600

BUILDLAB_STR: win7sp1_ldr

BUILDOSVER_STR: 6.1.7601.23915.amd64fre.win7sp1_ldr.170913-0600

ANALYSIS_SESSION_ELAPSED_TIME: d39

ANALYSIS_SOURCE: KM

FAILURE_ID_HASH_STRING: km:x64_0x50_stackptr_error_ntfs!memcpy+250

FAILURE_ID_HASH: {3cb1e7b2-ecc5-5c98-88a7-ac9f807c58ae}

Followup: MachineOwner

Our minifilter is not in the call stack but active at the time of the crash. It tries to write data to a sparse file using FltWriteFile. From looking at our application logs it is very likely that all observed crashes are caused by the same file.

Question:
Is there an easy way to figure out the file object that the system thread tries to write? This would help finding out what files trigger the issue.

Thanks,
Lars

rod_widdowson · March 26, 2018, 4:29am

> Question:

Is there an easy way to figure out the file object that the system thread
tries to write? This
would help finding out what files trigger the issue.

Its probably the second parameters to NtfsFspDispatch. Also Fat can
sometimes be instructive. Fat Isn’t NTFS but they were originally written
at the same time by a colleagues so

Requires_lock_held(Global_critical_region)
NTSTATUS
FatCommonWrite (
IN PIRP_CONTEXT IrpContext,
IN PIRP Irp
)

Maybe it’s also the second parameter to NtfsCommonWrite.

From there it’s “just” x64 calling standard. Good luck!

R

Lars_Diehl · March 26, 2018, 12:16pm

> NTSTATUS

FatCommonWrite (
IN PIRP_CONTEXT IrpContext,
IN PIRP Irp
)

Maybe it’s also the second parameter to NtfsCommonWrite.
From there it’s “just” x64 calling standard. Good luck!

Hi Rod,

thanks for your inspiration. You put me back on track…
And yes the second par is the irp I was searching for:

1: kd> kv

Child-SP RetAddr : Args to Child : Call Site

00 fffff88001fdc118 fffff8000194770e : 0000000000000050 fffff88007d10038 0000000000000000 fffff88001fdc280 : nt!KeBugCheckEx
01 fffff88001fdc120 fffff800018c8f2e : 0000000000000000 fffff88007d10038 0000000000000000 0000000000000000 : nt! ?? ::FNODOBFM::string'+0x3bdaf 02 fffff88001fdc280 fffff88001627ec0 : fffff88001648810 fffffa8007b43cc0 fffff88000000000 0000000000000001 : nt!KiPageFault+0x16e (TrapFrame @ fffff88001fdc280)
03 fffff88001fdc418 fffff88001648810 : fffffa8007b43cc0 fffff88000000000 0000000000000001 0000000000000800 : Ntfs!memcpy+0x250
04 fffff88001fdc420 fffff880016494d5 : fffff88001fdc780 fffff88001fdc5b8 0000000000000000 fffffa800e8fa010 : Ntfs!NtfsCopyFromMdl+0x18d
05 fffff88001fdc500 fffff88001622ef5 : fffff8a0192bd820 fffffa800e8fa000 0000000000000000 0000000000010000 : Ntfs!NtfsPrepareSparseWriteBuffer+0x85
06 fffff88001fdc550 fffff8800162d8a9 : fffffa80076d6e40 fffffa800e8fa010 fffff8a0192bd820 0000000000020000 : Ntfs!NtfsPrepareComplexBuffers+0x295
07 fffff88001fdc6b0 fffff8800162cdf0 : fffff8a0192bd820 0000000000000000 fffff88001fdc7d0 000000000001f800 : Ntfs!NtfsPrepareBuffers+0x179
08 fffff88001fdc730 fffff88001630f13 : fffffa80076d6e40 fffffa800e8fa010 0000000000000000 fffff880016a5b00 : Ntfs!NtfsNonCachedIo+0x310
09 fffff88001fdc8f0 fffff8800161c25b : fffffa80076d6e40 fffffa800e8fa010 fffff8a0c0000000 fffffa8000001000 : Ntfs!NtfsCommonWrite+0x2f64
0a fffff88001fdcaa0 fffff800018d5085 : 0000000000000000 fffff88005f3f300 0000000000000000 fffffa8000000000 : Ntfs!NtfsFspDispatch+0x28b
0b fffff88001fdcb70 fffff80001b65622 : 0000000000000000 fffffa8006d1e040 0000000000000080 fffffa8006cae970 : nt!ExpWorkerThread+0x111
0c fffff88001fdcc00 fffff800018bcda6 : fffff88001ee1180 fffffa8006d1e040 fffffa8006d1f660 0000000000000000 : nt!PspSystemThreadStartup+0x5a
0d fffff88001fdcc40 0000000000000000 : fffff88001fdd000 fffff88001fd7000 fffff88001fdc440 0000000000000000 : nt!KiStartSystemThread+0x16
1: kd> !irp fffffa80`0e8fa010
Irp is active with 8 stacks 7 is current (= 0xfffffa800e8fa290)
Mdl=fffffa80070c9860: No System Buffer: Thread fffffa800e3feb50: Irp stack trace.
cmd flg cl Device File Completion-Context
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[IRP_MJ_WRITE(4), N/A(0)]
0 0 fffffa80073e4030 00000000 fffff8800162da10-fffffa8007b85a10
\FileSystem\Ntfs Ntfs!NtfsMasterIrpSyncCompletionRoutine
Args: 00000000 00000000 00000000 00000000

[IRP_MJ_WRITE(4), N/A(0)]
0 e1 fffffa80073e4030 fffffa8007590f20 fffff88000fa98f0-fffffa800eaeac30 Success Error Cancel pending
\FileSystem\Ntfs fltmgr!FltpSynchronizedOperationCompletion
Args: 00000f54 00000000 0001f800 00000000
[IRP_MJ_WRITE(4), N/A(0)]
0 0 fffffa80079348e0 fffffa8007590f20 00000000-00000000
\FileSystem\FltMgr
Args: 00000f54 00000000 0001f800 00000000

-Lars

Scott_Noone_OSR · March 26, 2018, 1:45pm

Just want to note for the archives that, despite the name, the “Args to
Child” are not really the arguments to the function. The first four
arguments are passed in registers and the “Args to Child” are the
Home/Spill/Shadow Space on the stack that’s part of the x64 ABI.

The Debug build functions will “home” the register arguments onto the stack
and thus these will be the arguments. Release build can use the Home Space
for whatever it wants. Looks like you got lucky in this case, though it’s
not the rule.

-scott
OSR
@OSRDrivers

Next Seminar: Windows Internals and Software Driver Development
9-13 April 2018, Sterling, VA
https://www.osr.com/seminars/software-drivers/

Lars_Diehl · March 28, 2018, 5:11am

Just for the records:

The issue is clear now. We were not handling FltWriteFile correctly. We did not ensure sector alinged blocks when writing the data to the sparse file. Since we are piggybacking on a user file object we depend on the way the file was originally opened.

Scott, Rod:
Thanks again for the help!

-Lars