PPT files exception vs Byte order lock

adnan · August 29, 2012, 8:10am

I am getting an exception on my IRP_MJ_READ for PPT files only.
So I modified my ExceptionFilter and ExceptionHandler to handle it correctly. It reads the PPT file (even with the exception)

But I recently wrote byte order locks in my driver, so
When I lock the file using FsRtlProcessFileLock() or FsRtlFastLock(), and the exception is caught at the ExceptionFilter and then goes to ExceptionHandler, it crashes on IoCompleteRequest(Irp, IO_NO_INCREMENT);

How can I stop this BSOD.

I want to fix the exception in READ as well as, even if there is an exception, and the file is lock how to check/unlock in ExceptionFilter/Handler

mark-4 · August 29, 2012, 1:22pm

Hi Adnan
unless any of the APIs you are using specifically generate an exception which seems unlikely, your exception handler is simply masking the root cause. Just my opinion but it may be more useful if you comment out your exception handler, let it bugcheck and post the analysis instead?

Regards

Mark

adnan · September 2, 2012, 10:25am

Here is output of !analyze -v when the PPT files crash.

MODULE_NAME: mydriver

FAULTING_MODULE: 82834000 nt

DEBUG_FLR_IMAGE_TIMESTAMP: 504367c6

EXCEPTION_CODE: (NTSTATUS) 0xc00000e8 - An access to a user buffer failed at an “expected” point in time. This code is defined since the caller does not want to accept STATUS_ACCESS_VIOLATION in its filter.

FAULTING_IP:
nt!IoGetDeviceObjectPointer+1c6
82a97140 f6476008 test byte ptr [edi+60h],8

EXCEPTION_RECORD: 8bc1ba64 – (.exr 0xffffffff8bc1ba64)
ExceptionAddress: 82a97140 (nt!IoGetDeviceObjectPointer+0x000001c6)
ExceptionCode: c00000e8
ExceptionFlags: 00000001
NumberParameters: 0

CONTEXT: 8bc1b794 – (.cxr 0xffffffff8bc1b794)
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00040000 edi=849b96a0
eip=82a97140 esp=8bc1bac0 ebp=8bc1bae0 iopl=0 nv up ei pl zr na pe nc
cs=0009 ss=0013 ds=0023 es=0023 fs=0030 gs=0000 efl=00000246
nt!IoGetDeviceObjectPointer+0x1c6:
0009:82a97140 f6476008 test byte ptr [edi+60h],8 ds:0023:849b9700=08
Resetting default scope

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0x7E

CURRENT_IRQL: 0

LAST_CONTROL_TRANSFER: from 82a8d120 to 82a97140

STACK_TEXT:
WARNING: Stack unwind information not available. Following frames may be wrong.
8bc1bae0 82a8d120 849beae0 00000000 00000000 nt!IoGetDeviceObjectPointer+0x1c6
8bc1bb20 911cc311 849beae0 8bc1bc04 00000008 nt!CcCopyRead+0x107
8bc1bc4c 911cc7c2 849bd630 849beae0 8493a470 mydriver!mydriverReadFile+0x821 [c:\users\driver\read.c @ 734]
8bc1bca8 911c9654 849bd630 00000003 8493a3b8 mydriver!mydriverRead+0x162 [c:\users\driver\read.c @ 890]
8bc1bcc4 911c9958 849bd630 1adc1fe3 849bd642 mydriver!mydriverDispatchRequest+0x84 [c:\users\driver\irp.c @ 1102]
8bc1bd00 8288f173 849bd630 00000000 8488f4c0 mydriver!mydriverDequeueRequest+0xd8 [c:\users\driver\irp.c @ 1212]
8bc1bd50 82a1c46a 00000000 fe8c001b 00000000 nt!KeInsertQueueDpc+0x36e
8bc1bd90 828bd989 8288f066 00000000 00000000 nt!PsGetProcessSecurityPort+0xb5
00000000 00000000 00000000 00000000 00000000 nt!KeTestAlertThread+0x15a

FOLLOWUP_IP:
mydriver!mydriverReadFile+821 [c:\users\driver\read.c @ 734]
911cc311 0fb6c8 movzx ecx,al

FAULTING_SOURCE_CODE:
730: (PLARGE_INTEGER)&nByteOffset,
731: nBytesRead,
732: bCanWait,
733: pBuffer,

734: &Irp->IoStatus)) {
735: nStatus = STATUS_PENDING;
736: __leave;
737: }
738:
739: nStatus = Irp->IoStatus.Status;

SYMBOL_STACK_INDEX: 2

SYMBOL_NAME: mydriver!mydriverReadFile+821

FOLLOWUP_NAME: MachineOwner

IMAGE_NAME: mydriver.sys

STACK_COMMAND: .cxr 0xffffffff8bc1b794 ; kb

BUCKET_ID: WRONG_SYMBOLS

Followup: MachineOwner

OSR_Community_User · September 2, 2012, 4:38pm

This is a big hint:

First step: fix your symbols. Nothing in the stack backtrace is trustworthy without using the correct symbols. Given that Microsoft makes this TRIVIAL to set up properly, it’s difficult for those of us who do this routinely to understand why you aren’t even willing to do so.

If you don’t understand what I mean, just type “.symfix” into the debugger. Then type “.reload”. Then try your analysis again (“!analyze -v”). If you still see WRONG_SYMBOLS, you need to figure out why your symbols are not properly resolving. Use “!sym noisy” and then “.reload” and look at the output of the command to see why you aren’t getting the right symbols.

Tony
OSR

adnan · September 3, 2012, 2:32am

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

SYSTEM_THREAD_EXCEPTION_NOT_HANDLED (7e)
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.
Arguments:
Arg1: c00000e8, The exception code that was not handled
Arg2: 82a9d140, The address that the exception occurred at
Arg3: 80daaa64, Exception Record Address
Arg4: 80daa794, Context Record Address

Debugging Details:

EXCEPTION_CODE: (NTSTATUS) 0xc00000e8 - An access to a user buffer failed at an “expected” point in time. This code is defined since the caller does not want to accept STATUS_ACCESS_VIOLATION in its filter.

FAULTING_IP:
nt!CcMapAndCopyFromCache+11d
82a9d140 f6476008 test byte ptr [edi+60h],8

EXCEPTION_RECORD: 80daaa64 – (.exr 0xffffffff80daaa64)
ExceptionAddress: 82a9d140 (nt!CcMapAndCopyFromCache+0x0000011d)
ExceptionCode: c00000e8
ExceptionFlags: 00000001
NumberParameters: 0

CONTEXT: 80daa794 – (.cxr 0xffffffff80daa794)
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00040000 edi=849c8778
eip=82a9d140 esp=80daaac0 ebp=80daaae0 iopl=0 nv up ei pl zr na pe nc
cs=0009 ss=0013 ds=0023 es=0023 fs=0030 gs=0000 efl=00000246
nt!CcMapAndCopyFromCache+0x11d:
0009:82a9d140 f6476008 test byte ptr [edi+60h],8 ds:0023:849c87d8=08
Resetting default scope

DEFAULT_BUCKET_ID: INTEL_CPU_MICROCODE_ZERO

BUGCHECK_STR: 0x7E

PROCESS_NAME: System

CURRENT_IRQL: 2

ERROR_CODE: (NTSTATUS) 0xc00000e8 - An access to a user buffer failed at an “expected” point in time. This code is defined since the caller does not want to accept STATUS_ACCESS_VIOLATION in its filter.

LAST_CONTROL_TRANSFER: from 82a93120 to 82a9d140

STACK_TEXT:
80daaae0 82a93120 849c3458 00000000 00000000 nt!CcMapAndCopyFromCache+0x11d
80daab20 91181301 849c3458 80daac04 00000008 nt!CcCopyRead+0x107
80daac4c 911817b2 849933a8 849c3458 865b60e8 mydriver!mydriverReadFile+0x821 [c:\users\driver\read.c @ 734]
80daaca8 9117e654 849933a8 00000003 865b6030 mydriver!mydriverRead+0x162 [c:\users\driver\read.c @ 890]
80daacc4 9117e948 849933a8 11c3a5de 849933ba mydriver!mydriverDispatchRequest+0x84 [c:\users\driver\irp.c @ 1102]
80daad00 82895173 849933a8 00000000 8488dd48 mydriver!mydriverDequeueRequest+0xd8 [c:\users\driver\irp.c @ 1212]
80daad50 82a2246a 00000000 1977396d 00000000 nt!ExpWorkerThread+0x10d
80daad90 828c3989 82895066 00000000 00000000 nt!PspSystemThreadStartup+0x9e
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19

FOLLOWUP_IP:
mydriver!mydriverReadFile+821 [c:\users\driver\read.c @ 734]
91181301 0fb6c8 movzx ecx,al

FAULTING_SOURCE_CODE:
730: (PLARGE_INTEGER)&nByteOffset,
731: nBytesRead,
732: bCanWait,
733: pBuffer,

734: &Irp->IoStatus)) {
735: nStatus = STATUS_PENDING;
736: __leave;
737: }
738:
739: nStatus = Irp->IoStatus.Status;

SYMBOL_STACK_INDEX: 2

SYMBOL_NAME: mydriver!mydriverReadFile+821

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: mydriver

IMAGE_NAME: mydriver.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 50444c17

STACK_COMMAND: .cxr 0xffffffff80daa794 ; kb

FAILURE_BUCKET_ID: 0x7E_mydriver!mydriverReadFile+821

BUCKET_ID: 0x7E_mydriver!mydriverReadFile+821

Followup: MachineOwner

Amritanshu_Johri · September 3, 2012, 5:38am

In my opinion pBuffer doesn’t contain a valid memory address. can you confirm?

adnan · September 3, 2012, 6:01am

How can I confirm this?

Amritanshu_Johri · September 3, 2012, 8:03am

When you are in correct context (see .cxr), then

ensure you have the right value being displayed for pBuffer, mostly
dt pBuffer should work, but verify using disassembly or
use dbgprint etc.
then do a dd for the value in pBuffer, you will see that debugger
is not able to resolve its content.
!pte virtual address to double check
Figure out whats going on with pBuffer, where is it coming from etc.

I think, you might conclude that pBuffer is not valid because most
likely it is a user mode buffer belonging to different process in
system process’ address space (?)

HTH,
Amritanshu

On Mon, Sep 3, 2012 at 3:29 PM, wrote:
> How can I confirm this?
>
> —
> NTFSD is sponsored by OSR
>
> For our schedule of debugging and file system 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

OSR_Community_User · September 3, 2012, 3:50pm

In looking at the instruction, it wants to move something to [edi+60], and
edi is a kernel address (at least in a default 32-bit system; a 3GB user
space changes that picture). So something else is wrong here, it does not
appear to be using a user address. But the thing pointed to by edi does
not exist or is write-protected.

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

SYSTEM_THREAD_EXCEPTION_NOT_HANDLED (7e)
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.
Arguments:
Arg1: c00000e8, The exception code that was not handled
Arg2: 82a9d140, The address that the exception occurred at
Arg3: 80daaa64, Exception Record Address
Arg4: 80daa794, Context Record Address

Debugging Details:

EXCEPTION_CODE: (NTSTATUS) 0xc00000e8 - An access to a user buffer failed
at an “expected” point in time. This code is defined since the caller does
not want to accept STATUS_ACCESS_VIOLATION in its filter.

FAULTING_IP:
nt!CcMapAndCopyFromCache+11d
82a9d140 f6476008 test byte ptr [edi+60h],8

EXCEPTION_RECORD: 80daaa64 – (.exr 0xffffffff80daaa64)
ExceptionAddress: 82a9d140 (nt!CcMapAndCopyFromCache+0x0000011d)
ExceptionCode: c00000e8
ExceptionFlags: 00000001
NumberParameters: 0

CONTEXT: 80daa794 – (.cxr 0xffffffff80daa794)
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00040000
edi=849c8778
eip=82a9d140 esp=80daaac0 ebp=80daaae0 iopl=0 nv up ei pl zr na pe
nc
cs=0009 ss=0013 ds=0023 es=0023 fs=0030 gs=0000
efl=00000246
nt!CcMapAndCopyFromCache+0x11d:
0009:82a9d140 f6476008 test byte ptr [edi+60h],8
ds:0023:849c87d8=08
Resetting default scope

DEFAULT_BUCKET_ID: INTEL_CPU_MICROCODE_ZERO

BUGCHECK_STR: 0x7E

PROCESS_NAME: System

CURRENT_IRQL: 2

ERROR_CODE: (NTSTATUS) 0xc00000e8 - An access to a user buffer failed at
an “expected” point in time. This code is defined since the caller does
not want to accept STATUS_ACCESS_VIOLATION in its filter.

LAST_CONTROL_TRANSFER: from 82a93120 to 82a9d140

STACK_TEXT:
80daaae0 82a93120 849c3458 00000000 00000000
nt!CcMapAndCopyFromCache+0x11d
80daab20 91181301 849c3458 80daac04 00000008 nt!CcCopyRead+0x107
80daac4c 911817b2 849933a8 849c3458 865b60e8
mydriver!mydriverReadFile+0x821 [c:\users\driver\read.c @ 734]
80daaca8 9117e654 849933a8 00000003 865b6030 mydriver!mydriverRead+0x162
[c:\users\driver\read.c @ 890]
80daacc4 9117e948 849933a8 11c3a5de 849933ba
mydriver!mydriverDispatchRequest+0x84 [c:\users\driver\irp.c @ 1102]
80daad00 82895173 849933a8 00000000 8488dd48
mydriver!mydriverDequeueRequest+0xd8 [c:\users\driver\irp.c @ 1212]
80daad50 82a2246a 00000000 1977396d 00000000 nt!ExpWorkerThread+0x10d
80daad90 828c3989 82895066 00000000 00000000
nt!PspSystemThreadStartup+0x9e
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19

FOLLOWUP_IP:
mydriver!mydriverReadFile+821 [c:\users\driver\read.c @ 734]
91181301 0fb6c8 movzx ecx,al

FAULTING_SOURCE_CODE:
730: (PLARGE_INTEGER)&nByteOffset,
731: nBytesRead,
732: bCanWait,
733: pBuffer,
> 734: &Irp->IoStatus)) {
735: nStatus = STATUS_PENDING;
736: __leave;
737: }
738:
739: nStatus = Irp->IoStatus.Status;

SYMBOL_STACK_INDEX: 2

SYMBOL_NAME: mydriver!mydriverReadFile+821

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: mydriver

IMAGE_NAME: mydriver.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 50444c17

STACK_COMMAND: .cxr 0xffffffff80daa794 ; kb

FAILURE_BUCKET_ID: 0x7E_mydriver!mydriverReadFile+821

BUCKET_ID: 0x7E_mydriver!mydriverReadFile+821

Followup: MachineOwner

NTFSD is sponsored by OSR

For our schedule of debugging and file system 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

adnan · September 4, 2012, 1:29am

Well, the same code works fine for other type of files. DOC file opens fine without any problem.
txt files are ok, but notepad don’t have caching enable, so we can skip it. PDF files opens perfactly.

What could be wrong with PPT files only?

Amritanshu_Johri · September 4, 2012, 4:56am

On Tue, Sep 4, 2012 at 1:19 AM, wrote:
> In looking at the instruction, it wants to move something to [edi+60], and
> edi is a kernel address (at least in a default 32-bit system; a 3GB user
> space changes that picture). So something else is wrong here, it does not
> appear to be using a user address. But the thing pointed to by edi does
> not exist or is write-protected.

You are right about the instruction being shown for which exception
was raised, it is a test operation probably [edi+60] points to a flag
or something, the instruction is just testing if msb is set.

The fact that it is not cx0005 but cx00e8 implies that the the
exception was raised for a user mode address. Exceptions for kernel
mode addresses cannot be handled in try except, so the last
instruction getting executed can be taken as a hint to what is going
wrong (by disassembling CcMapAndCopyFromCache) but I would suggest
start from what you are passing as user buffer.

adnan · September 4, 2012, 8:14am

I’m not passing anything to the buffer. I am reading data to the buffer.
Since this is PPT file, the contents of buffer are not simply ASCI chars.

When I use the ExceptionFilter, I get MULTIPLE_IRP_COMPLETE _REQUESTS in BSOD.

First for me is how to avoid this exception, because the same code works fine for other files.

adnan · September 4, 2012, 8:30am

output of !analyze -v after using verifier.exe with standard settings.

PAGE_FAULT_IN_FREED_SPECIAL_POOL (cc)
Memory was referenced after it was freed.
This cannot be protected by try-except.
When possible, the guilty driver’s name (Unicode string) is printed on
the bugcheck screen and saved in KiBugCheckDriver.
Arguments:
Arg1: 9fac2e28, memory referenced
Arg2: 00000000, value 0 = read operation, 1 = write operation
Arg3: 82b619c5, if non-zero, the address which referenced memory.
Arg4: 00000000, Mm internal code.

Debugging Details:

READ_ADDRESS: 9fac2e28 Special pool

FAULTING_IP:
nt!IovpCompleteRequest+10
82b619c5 8b48e8 mov ecx,dword ptr [eax-18h]

MM_INTERNAL_CODE: 0

DEFAULT_BUCKET_ID: INTEL_CPU_MICROCODE_ZERO

BUGCHECK_STR: 0xCC

PROCESS_NAME: POWERPNT.EXE

CURRENT_IRQL: 2

IRP_ADDRESS: 00ac2e00

TRAP_FRAME: 88a33b8c – (.trap 0xffffffff88a33b8c)
ErrCode = 00000000
eax=9fac2e40 ebx=8b5e3bb0 ecx=8b5be930 edx=88a31000 esi=9fac2e00 edi=00000000
eip=82b619c5 esp=88a33c00 ebp=88a33c04 iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
nt!IovpCompleteRequest+0x10:
82b619c5 8b48e8 mov ecx,dword ptr [eax-18h] ds:0023:9fac2e28=???
Resetting default scope

LAST_CONTROL_TRANSFER: from 8290e559 to 82894cf0

STACK_TEXT:
88a336ec 8290e559 00000003 c163b93b 00000065 nt!RtlpBreakWithStatusInstruction
88a3373c 8290f055 00000003 8b5be930 0000001f nt!KiBugCheckDebugBreak+0x1c
88a33b00 8289ad87 00000050 9fac2e28 00000000 nt!KeBugCheck2+0x68b
88a33b74 82874a48 00000000 9fac2e28 00000000 nt!MmAccessFault+0xbf
88a33b74 82b619c5 00000000 9fac2e28 00000000 nt!KiTrap0E+0xdc
88a33c04 8289d70b c163b24f 8b5e3bb0 9fac2e00 nt!IovpCompleteRequest+0x10
88a33c48 82a40aa5 00ac2e40 88a33c74 88a33c78 nt!IopCompleteRequest+0x4a
88a33c7c 82a41944 00000000 8b5e3bb0 00000001 nt!IopSynchronousServiceTail+0x240
88a33d08 8287185a 8b4d7030 9fac2e00 00000000 nt!NtReadFile+0x644
88a33d08 77a170a6 8b4d7030 9fac2e00 00000000 nt!KiFastCallEntry+0x12a
0030e02c 77a162c4 75e1cfde 00000354 00000000 ntdll!KiIntSystemCall+0x6
0030e030 75e1cfde 00000354 00000000 00000000 ntdll!ZwReadFile+0xc
0030e094 77789bba 00000354 0030e1c0 00000008 KERNELBASE!ReadFile+0xaa
0030e0dc 6758c42b 00000354 0030e1c0 00000008 kernel32!ReadFileImplementation+0xf0
WARNING: Stack unwind information not available. Following frames may be wrong.
0030e12c 6758c271 00000000 00000000 0030e1c0 mso+0x24c42b
0030e194 6758c16a 0340b788 00000000 00000000 mso+0x24c271
0030e1c8 678e7f34 00000000 00000000 0030e43c mso+0x24c16a
0030e1d8 6995b332 0340b788 00000000 00000000 mso+0x5a7f34
0030e43c 6995b64b 0030f710 60ee3f46 00312f90 ppcore!DllGetLCID+0x240b0
003107bc 69967366 02fe6024 00310874 00000000 ppcore!DllGetLCID+0x243c9
00312eec 699eab23 00312ff0 001e9180 00312f38 ppcore!DllGetLCID+0x300e4
00314060 699db044 00315144 003140d0 00000804 ppcore!DllGetLCID+0xb38a1
00315368 699dad2c 00000000 00000000 00000000 ppcore!DllGetLCID+0xa3dc2
00315380 699dacf0 00000000 00000000 00000000 ppcore!DllGetLCID+0xa3aaa
00317480 699de6a6 00000000 00000000 00000000 ppcore!DllGetLCID+0xa3a6e
00318b7c 698e2bd4 02fe6000 698e2b7b 00000000 ppcore!DllGetLCID+0xa7424
00318b94 69b3d9a7 00318bd4 00000000 00000000 ppcore!PPMain+0x1bda6
00318bcc 69a476e4 02fe6000 00318c34 00000800 ppcore!DllGetLCID+0x206725
0031b118 698c7934 0031b398 00000001 00000001 ppcore!DllGetLCID+0x110462
0031e6b8 698c6e85 0031f938 60eec1aa 2d243040 ppcore!PPMain+0xb06
0031f950 2d2415ae 2d241575 2d240000 00000000 ppcore!PPMain+0x57
0031f9e4 7778ed6c 7ffd9000 0031fa30 77a3377b POWERPNT+0x15ae
0031f9f0 77a3377b 7ffd9000 779dc1f2 00000000 kernel32!BaseThreadInitThunk+0xe
0031fa30 77a3374e 2d2410c8 7ffd9000 ffffffff ntdll!__RtlUserThreadStart+0x70
0031fa48 00000000 2d2410c8 7ffd9000 00000000 ntdll!_RtlUserThreadStart+0x1b

STACK_COMMAND: kb

FOLLOWUP_IP:
nt!IovpCompleteRequest+10
82b619c5 8b48e8 mov ecx,dword ptr [eax-18h]

SYMBOL_STACK_INDEX: 5

SYMBOL_NAME: nt!IovpCompleteRequest+10

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: nt

IMAGE_NAME: ntkrnlmp.exe

DEBUG_FLR_IMAGE_TIMESTAMP: 4ea76e9b

FAILURE_BUCKET_ID: 0xCC_VRF_nt!IovpCompleteRequest+10

BUCKET_ID: 0xCC_VRF_nt!IovpCompleteRequest+10