Windows System Software -- Consulting, Training, Development -- Unique Expertise, Guaranteed Results

Home› NTFSD

Before Posting...

Please check out the Community Guidelines in the Announcements and Administration Category.

More Info on Driver Writing and Debugging


The free OSR Learning Library has more than 50 articles on a wide variety of topics about writing and debugging device drivers and Minifilters. From introductory level to advanced. All the articles have been recently reviewed and updated, and are written using the clear and definitive style you've come to expect from OSR over the years.


Check out The OSR Learning Library at: https://www.osr.com/osr-learning-library/


Kaspersky combined with our minifilter causes very few machines to freeze? How to find the cause?

brad_Hbrad_H Member Posts: 187
edited September 2022 in NTFSD

We have a file protection minifilter that protects some files from getting written on. The problem is that on very few systems that have both kasperseky and our minifilter, sometimes the system "freezes", but its not a full freeze, mouse signals seems to still work because they can move the mouse, but thats the only thing that works, and for example cntrl+alt+delete doesnt work to bring up task manager. This happens both in Win7 and Win10 machines, And if they unload our driver, the machines no longer freeze.
The problem is that when the machine freezes like this, we can only move the mouse so the output of dbgview or procmon cannot be captured anymore.

So we set up the required keys in the kbdhid service's registry to force BSOD, and indeed that one worked and we managed to get a full kernel dump to work it and find out what is happening.

So I thought i ask the experts here on how should i go on about finding the root cause of this freeze? What windbg commands do you guys suggest i should use to find what is causing this?

· Share on Facebook

Comments

  • rod_widdowsonrod_widdowson Member - All Emails Posts: 1,255

    My go to behavior is pretty "brute force and ignorance" but FWIW:

    • .logappend to a file (the next two commands product a lot of output will be long)
    • !locks
    • !process 0 7 (this will take a fair chunk of time)
       

    Then open the log file in an editor where it’s easy to search.
     

    9 times out of 10 the output of !locks will lead you to a deadlock then its just a matter of working out what you are holding that Kaspersky is taking umbrage to.
     

    From your description it feels like something is blocked while holding the system volume locked - all the other threads will be backed up behind that - it's a matter of working out why that thread isn't moving
     

    If !locks doesn't help you are going to have to spelunk through all the threads (the output of the !process command) looking for candidates for a deadlock -look for threads with your driver on the stack or with kaspersky on the stack.
     

    !stacks 2 <yourdrvier.sys> just lists the threads where you are on the stack and can be helpful but I find that I usually need to be able to peruse all the threads at some stage and so doing it up front saves me time in the long run.

    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187

    @rod_widdowson said:
    My go to behavior is pretty "brute force and ignorance" but FWIW:

    • .logappend to a file (the next two commands product a lot of output will be long)
    • !locks
    • !process 0 7 (this will take a fair chunk of time)
       

    Then open the log file in an editor where it’s easy to search.
     

    9 times out of 10 the output of !locks will lead you to a deadlock then its just a matter of working out what you are holding that Kaspersky is taking umbrage to.
     

    From your description it feels like something is blocked while holding the system volume locked - all the other threads will be backed up behind that - it's a matter of working out why that thread isn't moving
     

    If !locks doesn't help you are going to have to spelunk through all the threads (the output of the !process command) looking for candidates for a deadlock -look for threads with your driver on the stack or with kaspersky on the stack.
     

    !stacks 2 <yourdrvier.sys> just lists the threads where you are on the stack and can be helpful but I find that I usually need to be able to peruse all the threads at some stage and so doing it up front saves me time in the long run.

    Hi Rod, thank you for the reply.

    I am looking through the output of the commands you suggested as i am writing this, but as a side note, i found our driver and kaspersky's klfle in the stack of one of the cpu cores, although i am not sure whether its related to the problem or not, but in this stack we are calling FltCreateFile and then kaspersky is calling FltGetFileNameInformation, probably on the filename that we just tried to open. And we are opening the file using FILE_SHARE_READ/WRITE/DELETE and also with the READ+WRITE+SYNCHRONIZE access and FILE_SYNCHRONOUS_IO_NONALERT flag, and the file is a local file and not a network file.

    nt!KxReleaseQueuedSpinLock+0x23
nt!ExpReleaseResourceForThreadLite+0x1f6
NTFS!NtfsReleaseFcb+0x4b
NTFS!NtfsCommonQueryInformation$fin$0+0x6c
nt!_C_specific_handler+0x18e
nt!RtlpExecuteHandlerForUnwind+0xd
nt!RtlUnwindEx+0x432
nt!_C_specific_handler+0xe2
nt!RtlpExecuteHandlerForException+0xd
nt!RtlDispatchException+0x421
nt!RtlRaiseStatus+0x4e
NTFS!NtfsRaiseStatusInternal+0x6c
NTFS!NtfsCommonQueryInformation+0xbfc
NTFS!NtfsFsdDispatchSwitch+0xcc
NTFS!NtfsFsdDispatchWait+0x40
FLTMGR!FltpQueryInformationFile+0x112
FLTMGR!FltpGetFileName+0x30c
FLTMGR!FltpGetOpenedFileName+0x19
FLTMGR!FltpCallOpenedFileNameHandler+0x2b
FLTMGR!FltpExpandFilePathWorker+0x445
FLTMGR!FltpExpandFilePath+0x1a
FLTMGR!FltpGetNormalizedFileNameWorker+0x112
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x115
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
luafv!LuafvGenerateFileName+0x4c
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x113
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
wcifs!WcGenerateFileName+0x44
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x115
FLTMGR!FltpGetFileNameInformation+0x5e1
FLTMGR!FltGetFileNameInformation+0x1b0
klfle+0x610f0      ----> kaspersky
klfle+0x57950     ----> kaspersky
FLTMGR!FltpPerformPreCallbacks+0x2ea
FLTMGR!FltpPassThroughInternal+0x88
FLTMGR!FltpCreate+0x2e1
nt!IopParseDevice+0x168f
nt!ObpLookupObjectName+0x8af
nt!ObOpenObjectByNameEx+0x1dd
nt!IopCreateFile+0x860
nt!IoCreateFileEx+0x115
FLTMGR!FltpCreateFile+0x1cd
FLTMGR!FltCreateFile+0x8d
ourdriver+0x220a     ----> ourdriver

    output of locks:

    3: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks......

Resource @ 0xffffb408db5f5a08    Shared 4 owning threads
    Contention Count = 95
    NumberOfSharedWaiters = 46
    NumberOfExclusiveWaiters = 1
     Threads: ffffb408e3bbc080-01<*> ffffb408de8d3080-01<*> ffffb408de8e4080-01<*> ffffb408e36d7800-01<*> 
              ffffb408e3751080-01    ffffb408e390d080-01    ffffb408e225e800-01    ffffb408e3448040-01    
              ffffb408de94f800-01    ffffb408def17080-01    ffffb408debb5800-01    ffffb408df0af080-01    
              ffffb408e3b68800-01    ffffb408dbdbe080-01    ffffb408df282080-01    ffffb408e1d58080-01    
              ffffb408e3802080-01    ffffb408e3be3800-01    ffffb408e1f6e040-01    ffffb408e1bd4080-01    
              ffffb408e2bf2800-01    ffffb408e367d080-01    ffffb408e3af5800-01    ffffb408dec8a800-01    
              ffffb408e4515080-01    ffffb408e414a800-01    ffffb408e373f800-01    ffffb408e38d8080-01    
              ffffb408df748080-01    ffffb408dd561080-01    ffffb408d9cd3080-01    ffffb408e1bf1080-01    
              ffffb408e3928080-01    ffffb408e39c5800-01    ffffb408e41dc080-01    ffffb408e4103800-01    
              ffffb408e374d040-01    ffffb408df3cc080-01    ffffb408e3768040-01    ffffb408e4973040-01    
              ffffb408df4a6740-01    ffffb408dea8b080-01    ffffb408df702080-01    ffffb408dd6b9080-01    
              ffffb408e14f7080-01    ffffb408df996800-01    ffffb408e1e9c800-01    ffffb408df63c080-01    
              ffffb408e3363180-01    ffffb408dddc4080-01<*> 

     Threads Waiting On Exclusive Access:
              ffffb408e3642800       
KD: Scanning for held locks....................................................................................................

Resource @ 0xffffb408dd3ec940    Exclusively owned
    Contention Count = 3
    NumberOfExclusiveWaiters = 1
     Threads: ffffb408e2bf2800-01<*> 

     Threads Waiting On Exclusive Access:
              ffffb408ddf47080       
KD: Scanning for held locks.........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................

Resource @ 0xffffb408e35b8310    Exclusively owned
    Contention Count = 11
    NumberOfSharedWaiters = 3
    NumberOfExclusiveWaiters = 1
     Threads: ffffb408e3bbc080-02<*> ffffb408de8d3080-01    ffffb408de8e4080-01    ffffb408e262b040-01<*> 

     Threads Waiting On Exclusive Access:
              ffffb408e36d7800       
KD: Scanning for held locks.........................................................................................................

Resource @ 0xffffb408dab1fd60    Exclusively owned
     Threads: ffffb408e3bbc080-01<*> 

Resource @ 0xffffb408dab1fe10    Exclusively owned
     Threads: ffffb408e3bbc080-01<*> 
KD: Scanning for held locks.....................................
32227 total locks, 5 locks currently held
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187

    Looking at the output of !locks, it seems like there are no deadlocks, and looking through the output of !process 0 7, this is the only thread that i can find both our driver and kaspersky in the stack:

            THREAD ffffb408e36d7800  Cid 0294.2110  Teb: 0000009b5739f000 Win32Thread: 0000000000000000 WAIT: (WrResource) KernelMode Non-Alertable
            ffffb408dce876d0  SynchronizationEvent
        IRP List:
            ffffb408e49bf0a0: (0006,0550) Flags: 00000884  Mdl: 00000000
            ffffb408e4917010: (0006,05e0) Flags: 00060830  Mdl: 00000000
        Not impersonating
        DeviceMap                 ffffa0866644e7c0
        Owning Process            ffffb408e37f5080       Image:         chrome.exe
        Attached Process          N/A            Image:         N/A
        Wait Start TickCount      409547         Ticks: 89 (0:00:00:01.390)
        Context Switch Count      741            IdealProcessor: 2             
        UserTime                  00:00:00.031
        KernelTime                00:00:00.015
        Win32 Start Address 0x00007ffd3c481460
        Stack Init ffffdc007f757fd0 Current ffffdc007f757600
        Base ffffdc007f758000 Limit ffffdc007f751000 Call 0000000000000000
        Priority 15 BasePriority 8 PriorityDecrement 112 IoPriority 2 PagePriority 5
        Child-SP          RetAddr           : Args to Child                                                           : Call Site
        ffffdc00`7f757640 fffff801`5990906d : ffffdc00`00000000 00000000`00000001 00000000`00000000 fffff801`599533a9 : nt!KiSwapContext+0x76
        ffffdc00`7f757780 fffff801`59908b0f : ffffb408`e36d7800 ffffb408`e36d7900 00000000`00000000 00000000`00000000 : nt!KiSwapThread+0x17d
        ffffdc00`7f757830 fffff801`5990adc8 : ffffb408`00000000 ffffb408`e35b8310 00000000`00000025 ffffb408`e36d7800 : nt!KiCommitThreadWait+0x14f
        ffffdc00`7f7578d0 fffff801`599520be : ffffb408`e35b8310 ffffb408`dce876d0 ffffdc00`00000000 00000000`00000000 : nt!ExpWaitForResource+0x2a8
        ffffdc00`7f7579a0 fffff80b`eadb6b08 : 00000000`00000002 00000000`00000000 ffffa086`7418c770 00000000`00000000 : nt!ExAcquireResourceExclusiveLite+0x27e
        ffffdc00`7f757a20 fffff80b`eadb690d : ffffb408`e1d94948 ffffa086`7418c770 ffffb408`e1d94980 00000000`00000000 : NTFS!NtfsAcquireExclusiveFcb+0x78
        ffffdc00`7f757a90 fffff80b`eae9116a : ffffb408`db5f5301 ffffb408`db5f53f0 00000000`00000000 ffffa086`00000000 : NTFS!NtfsAcquireFcbWithPaging+0xbd
        ffffdc00`7f757b10 fffff80b`eae90118 : ffffb408`e1d94948 ffffb408`db5f64f8 ffffa086`7418c770 fffff80b`eadb6101 : NTFS!NtfsFindPrefixHashEntry+0xa6a
        ffffdc00`7f757c20 fffff80b`eae8c6fe : ffffb408`e1d94948 ffffb408`e49bf0a0 ffffb408`e49bf0a0 ffffdc00`7f757e88 : NTFS!NtfsFindStartingNode+0xa88
        ffffdc00`7f757d10 fffff80b`eae8bf7d : ffffb408`e1d94948 ffffb408`e49bf0a0 ffffdc00`79ed6300 ffffb408`e36d7800 : NTFS!NtfsCommonCreate+0x43e
        ffffdc00`7f757f50 fffff801`599f2d77 : ffffdc00`79ed62b0 00000000`00000000 000000db`e6eff0f8 00000000`00000000 : NTFS!NtfsCommonCreateCallout+0x1d
        ffffdc00`7f757f80 fffff801`599f2d3d : 00000000`00006000 00000000`00000000 00000000`00000012 fffff801`59994841 : nt!KxSwitchKernelStackCallout+0x27 (TrapFrame @ ffffdc00`7f757e40)
        ffffdc00`79ed60e0 fffff801`59994841 : 00000000`00000012 00000000`00006000 00000000`00000000 00000000`00000007 : nt!KiSwitchKernelStackContinue
        ffffdc00`79ed6100 fffff801`599944a6 : ffffdc00`79ed6190 00000000`00006000 00000000`00000008 00000000`00000009 : nt!KiExpandKernelStackAndCalloutOnStackSegment+0x241
        ffffdc00`79ed6190 fffff801`5999436f : 00000000`00000000 ffffdc00`79ed62b0 00000000`00000001 00000000`00000001 : nt!KiExpandKernelStackAndCalloutSwitchStack+0xa6
        ffffdc00`79ed61f0 fffff80b`eae8b89a : 00000000`00000000 00000000`00000000 ffffb408`e1d94948 00000000`00000001 : nt!KeExpandKernelStackAndCalloutInternal+0x2f
        ffffdc00`79ed6240 fffff80b`eb585206 : ffffb408`db5f5030 ffffb408`e49bf0a0 ffffdc00`79ed6500 00000000`00000001 : NTFS!NtfsFsdCreate+0x23a
        ffffdc00`79ed6460 fffff80b`eb5b4065 : fffff80b`eb5a4060 ffffdc00`79ed6570 ffffb408`db141801 ffffa086`76833380 : FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x1a6
        ffffdc00`79ed64f0 fffff801`59d2484f : 00000000`00000001 00000000`000000a7 ffffb408`00000060 ffffb408`e38ac488 : FLTMGR!FltpCreate+0x2f5
        ffffdc00`79ed65a0 fffff801`59d3805f : fffff801`59d231c0 fffff801`59d231c0 ffffdc00`79ed6890 ffffb408`daf10870 : nt!IopParseDevice+0x168f
        ffffdc00`79ed6790 fffff801`59d6c3fd : ffffb408`e4966100 ffffdc00`79ed69f0 ffffb408`00000240 ffffb408`d9cacf20 : nt!ObpLookupObjectName+0x8af
        ffffdc00`79ed6960 fffff801`59d8c610 : 00000000`00000001 00000000`00000000 ffffdc00`79ed6c60 ffffdc00`79ed6c98 : nt!ObOpenObjectByNameEx+0x1dd
        ffffdc00`79ed6aa0 fffff801`59d8bc99 : 00000000`00000900 00000000`00100001 ffffdc00`79ed6c98 ffffb408`e478beb0 : nt!IopCreateFile+0x860
        ffffdc00`79ed6b50 fffff80b`eb5cc4e2 : ffffb408`e478bdd0 00000000`00000000 00000000`00000028 ffffa086`767c9028 : nt!IoCreateFileEx+0x115
        ffffdc00`79ed6be0 fffff80b`eb5c38d6 : ffffb408`e38ac488 00000000`00000000 ffffb408`e478bdd0 ffffb408`db512400 : FLTMGR!FltpNormalizeNameFromCache+0x1a6
        ffffdc00`79ed6d10 fffff80b`eb5cd1b4 : 00000000`00000000 ffffb408`00000017 00000000`0000009e ffffb408`e478bdd0 : FLTMGR!FltpExpandShortNames+0xc082
        ffffdc00`79ed6da0 fffff80b`eb5ccb41 : 00000000`00000000 00000000`00000000 00000000`00000101 ffffb408`e475fe40 : FLTMGR!FltpGetNormalizedDestinationFileName+0x68
        ffffdc00`79ed6dd0 fffff80b`ead307e9 : 00000000`00000000 ffffa086`74860018 00000000`00000000 00000000`000001ae : FLTMGR!FltGetDestinationFileNameInformation+0x191
        ffffdc00`79ed6fb0 fffff80b`ead6a4b1 : ffffb408`00000001 00000000`00000002 00000000`00000000 ffffdc00`79ed7368 : klfle+0x207e9
        ffffdc00`79ed72f0 fffff80b`ead6c478 : ffffb408`e445e230 00000000`00000001 ffffb408`e4606a58 00000000`00000001 : klfle+0x5a4b1
        ffffdc00`79ed7460 fffff80b`eb5846ca : ffffb408`e4606af8 ffffb408`e4606980 ffffb408`e4606980 ffffb408`db512300 : klfle+0x5c478
        ffffdc00`79ed7510 fffff80b`eb584278 : ffffdc00`79ed76f0 00000000`00000000 ffffb408`e475fe06 ffffb408`db512300 : FLTMGR!FltpPerformPreCallbacks+0x2ea
        ffffdc00`79ed7620 fffff80b`eb583386 : 00000000`00000000 ffffdc00`79ed76f0 ffffb408`e4917010 ffffdc00`79ed7700 : FLTMGR!FltpPassThroughInternal+0x88
        ffffdc00`79ed7650 fffff80b`eb58312e : ffffb408`e2e82350 fffff80b`eb5b9e20 ffffb408`e2e82350 ffffb408`e2e82350 : FLTMGR!FltpPassThrough+0x1a6
        ffffdc00`79ed76d0 fffff80b`eb7a225d : ffffdc00`79ed7800 ffffb408`e475fe40 00000000`00000000 ffffb408`e45dfe80 : FLTMGR!FltpDispatch+0x9e
        ffffdc00`79ed7730 fffff80b`eb58e5f9 : ffffdc00`79ed7800 ffffb408`e475fe40 00000000`00000000 ffffb408`e2e82350 : ourdriver+0x220a
        ffffdc00`79ed7760 fffff80b`eb58312e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000001 : FLTMGR!FltpPassThrough+0xb419
        ffffdc00`79ed77e0 fffff801`598f64e7 : ffffb408`e4917010 01d8bbaa`838f72eb 01d8bbaa`838f72eb 01d8bbaa`839036c2 : FLTMGR!FltpDispatch+0x9e
        ffffdc00`79ed7840 fffff801`598f63bb : ffffb408`e475fe90 ffffb408`dd5a34d0 00000000`00000000 ffffb408`e4917560 : nt!IoCallDriverWithTracing+0x47
        ffffdc00`79ed78a0 fffff801`5998e8a5 : 00000000`00000000 ffffdc00`79ed7b00 00000000`00000000 00000000`00000001 : nt!IopCallDriverReference+0x9b
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited September 2022

    Interestingly, i just remembered a while ago we had a BSOD issue with another AV (manual BSOD, not a Windows BSOD), that also had a similar call stack:

    nt!KeBugCheckEx  --> In this case they manually BSOD themselves
avkmgr+0x33309   --> avira
avkmgr+0x34f70   --> avira
FLTMGR!FltpPerformPreCallbacksWorker+0x36c
FLTMGR!FltpPassThroughInternal+0x265
FLTMGR!FltpCreate+0x310
nt!IofCallDriver+0x55
nt!IoCallDriverWithTracing+0x34
nt!IopParseDevice+0x117d
nt!ObpLookupObjectName+0x3fe
nt!ObOpenObjectByNameEx+0x1fa
nt!IopCreateFile+0x40f
nt!IoCreateFileEx+0x11d
FLTMGR!FltpExpandFilePathWorker+0x32f
FLTMGR!FltpExpandFilePath+0x1e
FLTMGR!FltpGetNormalizedFileNameWorker+0x225
FLTMGR!FltpGetNormalizedFileNameCallout+0x11
nt!KxSwitchKernelStackCallout+0x2e
nt!KiSwitchKernelStackContinue
nt!KiExpandKernelStackAndCalloutOnStackSegment+0x19d
nt!KiExpandKernelStackAndCalloutSwitchStack+0xf2
nt!KeExpandKernelStackAndCalloutInternal+0x33
nt!KeExpandKernelStackAndCalloutEx+0x1d
FLTMGR!FltpCreateFileNameInformation+0x3a1
FLTMGR!HandleStreamListNotSupported+0x134
FLTMGR!FltpGetFileNameInformation+0x5c4
FLTMGR!FltGetFileNameInformation+0x101
avgntflt+0x33100   --> avira
avgntflt+0xaf55c   --> avira
avgntflt+0xaf2c5   --> avira
avgntflt+0xb77c1   --> avira
avgntflt+0xb72e2   --> avira
FLTMGR!FltpPerformPreCallbacksWorker+0x36c
FLTMGR!FltpPassThroughInternal+0x265
FLTMGR!FltpCreate+0x310
nt!IofCallDriver+0x55
nt!IoCallDriverWithTracing+0x34
nt!IopParseDevice+0x117d
nt!ObpLookupObjectName+0x3fe
nt!ObOpenObjectByNameEx+0x1fa
nt!IopCreateFile+0x40f
nt!IoCreateFileEx+0x11d
FLTMGR!FltpCreateFile+0x16f
FLTMGR!FltCreateFile+0x8d
ourdriver+0x220a   --> our driver
ourdriver+0x1d20   --> our driver
ourdriver+0x36a2   --> our driver
FLTMGR!FltpPerformPreCallbacksWorker+0x36c

    So in both cases, this starts in our preclose callback in the minifilter when we try to open a handle to the backup of file, using the name of the backup file that we stored on the context (and the name is correct), and in both cases, the target AV is calling FltGetFileNameInformation on that file after we use the FltCreateFile, anyone has any idea what is happening? I explained the flags that we pass to FltCreateFile in the above post for anyone interested.

    · Share on Facebook
  • Scott_Noone_(OSR)Scott_Noone_(OSR) Administrator Posts: 3,628

    What is thread ffffb408e3bbc080 doing?

    -scott
    OSR

    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187

    @Scott_Noone_(OSR) said:
    What is thread ffffb408e3bbc080 doing?

    This is a chrome.exe thread, and it seems like its doing some stuff one of its tmp files in appdata, and its kernel time seem to be relatively high compared to other threads:

    This is its callstack:

            THREAD ffffb408e3bbc080  Cid 0294.1ea8  Teb: 0000009b5739b000 Win32Thread: ffffb408e212a2c0 RUNNING on processor 3
        IRP List:
            ffffb408e3adc1c0: (0006,0550) Flags: 00000884  Mdl: 00000000
            ffffb408e494e010: (0006,05e0) Flags: 00000404  Mdl: 00000000
            ffffb408e4986010: (0006,05e0) Flags: 00000404  Mdl: 00000000
        Not impersonating
        DeviceMap                 ffffa0866644e7c0
        Owning Process            ffffb408e37f5080       Image:         chrome.exe
        Attached Process          N/A            Image:         N/A
        Wait Start TickCount      409569         Ticks: 67 (0:00:00:01.046)
        Context Switch Count      26149          IdealProcessor: 3             
        UserTime                  00:00:00.062
        KernelTime                00:03:28.390
        Win32 Start Address 0x00007ffd3c481460
        Stack Init ffffdc007b725fd0 Current ffffdc007b7232c0
        Base ffffdc007b726000 Limit ffffdc007b71f000 Call 0000000000000000
        Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
        Child-SP          RetAddr           : Args to Child                                                           : Call Site
        ffffdc00`7b721b70 fffff801`599528d6 : 00000000`00000000 fffff80b`eada0000 ffffdc00`7b723178 fffff801`599f1634 : nt!KxReleaseQueuedSpinLock+0x23
        ffffdc00`7b721ba0 fffff80b`eadb529b : 00000000`80000005 ffffdc00`7b722c50 ffffdc00`7b722502 fffff80b`eadc6b20 : nt!ExpReleaseResourceForThreadLite+0x1f6
        ffffdc00`7b721c80 fffff80b`eaeec3ec : fffff80b`eae060c4 ffffdc00`7b723210 00000000`000eb5c5 00000000`00000000 : NTFS!NtfsReleaseFcb+0x4b
        ffffdc00`7b721cc0 fffff801`599defae : 00000000`00000000 ffffdc00`7b721eb0 ffffffff`ffffffd2 fffff801`599e327c : NTFS!NtfsCommonQueryInformation$fin$0+0x6c
        ffffdc00`7b721d10 fffff801`599f7dad : ffffffff`ffffffff ffffdc00`7b721eb0 00000000`00000000 ffffdc00`7b722b00 : nt!_C_specific_handler+0x18e
        ffffdc00`7b721d80 fffff801`59998e12 : ffffffff`ffffffff ffffdc00`7b722b00 ffff8000`00000000 fffff801`599f6215 : nt!RtlpExecuteHandlerForUnwind+0xd
        ffffdc00`7b721db0 fffff801`599def02 : fffff80b`eae06124 ffffdc00`00000001 ffffdc00`7b7232f0 fffff801`598f9d32 : nt!RtlUnwindEx+0x432
        ffffdc00`7b722490 fffff801`599f7d2d : ffffffff`ffffffff ffffdc00`7b722630 00000000`00000000 00000000`00000292 : nt!_C_specific_handler+0xe2
        ffffdc00`7b722500 fffff801`599984a1 : ffffffff`ffffffff 00000000`00000000 ffff8000`00000000 00000000`00000000 : nt!RtlpExecuteHandlerForException+0xd
        ffffdc00`7b722530 fffff801`59999b06 : ffffffff`ffd016d8 00000000`00000003 00000000`80000005 fffff801`59820277 : nt!RtlDispatchException+0x421
        ffffdc00`7b722c30 fffff80b`eadb0950 : ffff3d5e`ef41a4f8 00000000`00000000 00000000`00000000 ffffa086`76dfe970 : nt!RtlRaiseStatus+0x4e
        ffffdc00`7b7231d0 fffff80b`eae8b1ae : ffffa086`7418c8b0 ffffdc00`7b723640 ffffdc00`7b723390 ffffdc00`7b723390 : NTFS!NtfsRaiseStatusInternal+0x6c
        ffffdc00`7b723210 fffff80b`eae8b49c : ffffdc00`7b723390 ffffb408`0000022a 00000000`0000033a ffffb408`00000003 : NTFS!NtfsCommonQueryInformation+0xbfe
        ffffdc00`7b7232f0 fffff80b`eae8b3b0 : ffffdc00`7b723390 ffffb408`e471daf0 ffffb408`e471daf0 00001f80`009f0015 : NTFS!NtfsFsdDispatchSwitch+0xcc
        ffffdc00`7b723370 fffff80b`eb5b823e : ffffb408`e471daf0 ffffdc00`7b723640 ffffdc00`7b7236a0 00000000`0000033a : NTFS!NtfsFsdDispatchWait+0x40
        ffffdc00`7b7235e0 fffff80b`eb5b51dc : ffffb408`e3235a80 00000000`00000000 ffffb408`e3235a80 00000000`80000005 : FLTMGR!FltpQueryInformationFile+0x112
        ffffdc00`7b723670 fffff80b`eb5b4e59 : ffffdc00`7b723890 ffffb408`e3235a80 ffffdc00`7b723890 00000000`00000000 : FLTMGR!FltpGetFileName+0x30c
        ffffdc00`7b723710 fffff80b`eb5b5887 : ffffa086`75561600 ffffdc00`00000000 fffff80b`eb5a5bc0 fffff80b`eb588cf2 : FLTMGR!FltpGetOpenedFileName+0x19
        ffffdc00`7b723740 fffff80b`eb5b2995 : ffffb408`e477b900 ffffb408`e477b930 ffffb408`db1418a0 ffffb408`e2bf41b0 : FLTMGR!FltpCallOpenedFileNameHandler+0x2b
        ffffdc00`7b723790 fffff80b`eb5b6276 : ffffdc00`7b726001 ffffdc00`7b710042 00000000`00000000 ffffb408`dcf16ce8 : FLTMGR!FltpExpandFilePathWorker+0x445
        ffffdc00`7b723900 fffff80b`eb5b57da : ffffb408`e477b900 ffffb408`e477b930 00000000`00000000 00000000`00000000 : FLTMGR!FltpExpandFilePath+0x1a
        ffffdc00`7b723950 fffff80b`eb5b565e : ffffb408`e477b930 ffffdc00`7b71f000 00000000`00000000 00000000`c00000bb : FLTMGR!FltpGetNormalizedFileNameWorker+0x112
        ffffdc00`7b723990 fffff80b`eb5b4c9c : ffffb408`e3bbc080 ffffa086`76b7fc70 00000001`00000039 fffff80b`eb5872cd : FLTMGR!FltpGetNormalizedFileName+0x1a
        ffffdc00`7b7239e0 fffff80b`eb588953 : c00000bb`00000000 ffffb408`e477b930 ffffb408`e4b210b0 ffffb408`db512970 : FLTMGR!FltpCreateFileNameInformation+0x32c
        ffffdc00`7b723a30 fffff80b`eb586e17 : ffffb408`db512300 ffffb408`e477b930 fffff80b`eb5a4060 00000000`c00000bb : FLTMGR!HandleStreamListNotSupported+0x113
        ffffdc00`7b723a70 fffff80b`eb587b20 : 00000001`00000026 00000000`00000000 00000000`00000000 00000000`00000000 : FLTMGR!FltpGetFileNameInformation+0x5e7
        ffffdc00`7b723b10 fffff80b`ef6fd54c : ffffb408`e477b930 ffffb408`e408fdf0 ffffa086`76b7fc80 ffffb408`db5123a0 : FLTMGR!FltGetFileNameInformation+0x1b0
        ffffdc00`7b723b90 fffff80b`eb5b58e5 : ffffdc00`7b723c58 00000000`c00000bb ffffb408`e408fdf0 ffffb408`db512400 : luafv!LuafvGenerateFileName+0x4c
        ffffdc00`7b723bc0 fffff80b`eb5b56f7 : ffffb408`e408fd00 ffffb408`e408fdf0 00000000`00000000 00000000`6e664d46 : FLTMGR!FltpCallOpenedFileNameHandler+0x89
        ffffdc00`7b723c10 fffff80b`eb5b565e : ffffb408`e408fdf0 ffffdc00`7b71f000 00000000`00000000 00000000`c00000bb : FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
        ffffdc00`7b723c50 fffff80b`eb5b4c9c : ffffb408`e3bbc080 00000000`6e664d46 ffffb408`e4027080 fffff80b`eb5872cd : FLTMGR!FltpGetNormalizedFileName+0x1a
        ffffdc00`7b723ca0 fffff80b`eb588953 : c00000bb`00000000 ffffb408`e408fdf0 ffffb408`e4b210b0 ffffb408`db512970 : FLTMGR!FltpCreateFileNameInformation+0x32c
        ffffdc00`7b723cf0 fffff80b`eb586e17 : ffffb408`db512300 ffffb408`e408fdf0 fffff80b`eb5a4060 00000000`c00000bb : FLTMGR!HandleStreamListNotSupported+0x113
        ffffdc00`7b723d30 fffff80b`eb587b20 : c00000bb`00000001 00000000`00000000 ffffb408`ddfd8010 fffff801`59ae320d : FLTMGR!FltpGetFileNameInformation+0x5e7
        ffffdc00`7b723dd0 fffff80b`ef73aa74 : 00000001`00000039 ffffb408`e3996e20 00000000`00000001 fffff801`59ae320d : FLTMGR!FltGetFileNameInformation+0x1b0
        ffffdc00`7b723e50 fffff80b`eb5b58e5 : ffffdc00`7b723f18 00000000`c00000bb 00000000`00000000 ffffb408`ddfdb980 : wcifs!WcGenerateFileName+0x44
        ffffdc00`7b723e80 fffff80b`eb5b56f7 : ffffb408`e3996e00 ffffb408`e3996e20 00000000`00000000 00000000`00000000 : FLTMGR!FltpCallOpenedFileNameHandler+0x89
        ffffdc00`7b723ed0 fffff80b`eb5b565e : ffffb408`e3996e20 ffffdc00`7b71f000 00000000`00000000 00000000`c00000bb : FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
        ffffdc00`7b723f10 fffff80b`eb5b4c9c : ffffb408`e3bbc080 ffffb408`db5123a0 ffffb408`e3996e20 fffff80b`eb5872cd : FLTMGR!FltpGetNormalizedFileName+0x1a
        ffffdc00`7b723f60 fffff80b`eb588953 : c00000bb`00000000 ffffb408`e3996e20 ffffb408`e4b210b0 ffffb408`db512970 : FLTMGR!FltpCreateFileNameInformation+0x32c
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited September 2022

    And after further investigating its IRP list and their corresponding FILE_OBJECT, it seems like all related to some tmp files in its cachestore, and all the IRPs (close,cleanup,create for \FileSystem\FltMgr) are pending?

    0: kd> !irp ffffb408e3adc1c0 2
Irp is active with 15 stacks 15 is current (= 0xffffb408e3adc680)
 No Mdl: No System Buffer: Thread ffffb408e3bbc080:  Irp stack trace.  
Flags = 00000884
ThreadListEntry.Flink = ffffb408e494e030
ThreadListEntry.Blink = ffffb408e3bbc6e8
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = ffffdc007b724a28
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000   
UserBuffer = ffffa0867675f280
&Tail.Overlay.DeviceQueueEntry = ffffb408e3adc238
Tail.Overlay.Thread = ffffb408e3bbc080
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = ffffb408e3adc680
Tail.Overlay.OriginalFileObject = ffffb408e4027080
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
     cmd  flg cl Device   File     Completion-Context
 [N/A(0), N/A(0)]
            0  0 00000000 00000000 00000000-00000000    

  ...




  [IRP_MJ_CREATE(0), N/A(0)]


            0  1 ffffb408db1418a0 ffffb408e4027080 00000000-00000000    pending
           \FileSystem\FltMgr
            Args: ffffdc007b724a80 01000020 00070080 00000000

Irp Extension present at 0xffffb408e3adc6c8:
0: kd> dt nt!_FILE_OBJECT ffffb408e4027080
   +0x000 Type             : 0n5
   +0x002 Size             : 0n216
   +0x008 DeviceObject     : 0xffffb408`daf108a0 _DEVICE_OBJECT
   +0x010 Vpb              : (null) 
   +0x018 FsContext        : (null) 
   +0x020 FsContext2       : (null) 
   +0x028 SectionObjectPointer : (null) 
   +0x030 PrivateCacheMap  : (null) 
   +0x038 FinalStatus      : 0n0
   +0x040 RelatedFileObject : (null) 
   +0x048 LockOperation    : 0 ''
   +0x049 DeletePending    : 0 ''
   +0x04a ReadAccess       : 0 ''
   +0x04b WriteAccess      : 0 ''
   +0x04c DeleteAccess     : 0 ''
   +0x04d SharedRead       : 0 ''
   +0x04e SharedWrite      : 0 ''
   +0x04f SharedDelete     : 0 ''
   +0x050 Flags            : 2
   +0x058 FileName         : _UNICODE_STRING "\Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt.tmp.backup"
   +0x068 CurrentByteOffset : _LARGE_INTEGER 0x0
   +0x070 Waiters          : 0
   +0x074 Busy             : 0
   +0x078 LastLock         : (null) 
   +0x080 Lock             : _KEVENT
   +0x098 Event            : _KEVENT
   +0x0b0 CompletionContext : (null) 
   +0x0b8 IrpListLock      : 0
   +0x0c0 IrpList          : _LIST_ENTRY [ 0xffffb408`e4027140 - 0xffffb408`e4027140 ]
   +0x0d0 FileObjectExtension : 0xffffb408`e4914870 Void
0: kd> !irp ffffb408e494e010 2
Irp is active with 17 stacks 17 is current (= 0xffffb408e494e560)
 No Mdl: No System Buffer: Thread ffffb408e3bbc080:  Irp stack trace.  
Flags = 00000404
ThreadListEntry.Flink = ffffb408e4986030
ThreadListEntry.Blink = ffffb408e3adc1e0
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = ffffdc007b725510
UserEvent = ffffdc007b725520
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000   
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = ffffb408e494e088
Tail.Overlay.Thread = ffffb408e3bbc080
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = ffffb408e494e560
Tail.Overlay.OriginalFileObject = ffffb408e33ff860
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
     cmd  flg cl Device   File     Completion-Context
 [N/A(0), N/A(0)]
            0  0 00000000 00000000 00000000-00000000    
    ...
            Args: 00000000 00000000 00000000 00000000


  [IRP_MJ_CLOSE(2), N/A(0)]


            0  1 ffffb408db1418a0 ffffb408e33ff860 00000000-00000000    pending
           \FileSystem\FltMgr
            Args: 00000000 00000000 00000000 00000000

Irp Extension present at 0xffffb408e494e5a8:
0: kd> dt nt!_FILE_OBJECT ffffb408e33ff860
   +0x000 Type             : 0n5
   +0x002 Size             : 0n216
   +0x008 DeviceObject     : 0xffffb408`daf108a0 _DEVICE_OBJECT
   +0x010 Vpb              : 0xffffb408`db001c80 _VPB
   +0x018 FsContext        : 0xffffa086`7678ac00 Void
   +0x020 FsContext2       : 0xffffa086`7678ae48 Void
   +0x028 SectionObjectPointer : 0xffffb408`dab1fdd8 _SECTION_OBJECT_POINTERS
   +0x030 PrivateCacheMap  : (null) 
   +0x038 FinalStatus      : 0n0
   +0x040 RelatedFileObject : (null) 
   +0x048 LockOperation    : 0 ''
   +0x049 DeletePending    : 0 ''
   +0x04a ReadAccess       : 0 ''
   +0x04b WriteAccess      : 0x1 ''
   +0x04c DeleteAccess     : 0 ''
   +0x04d SharedRead       : 0 ''
   +0x04e SharedWrite      : 0 ''
   +0x04f SharedDelete     : 0 ''
   +0x050 Flags            : 0x44042
   +0x058 FileName         : _UNICODE_STRING "\Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt.tmp"
   +0x068 CurrentByteOffset : _LARGE_INTEGER 0x147
   +0x070 Waiters          : 0
   +0x074 Busy             : 0
   +0x078 LastLock         : (null) 
   +0x080 Lock             : _KEVENT
   +0x098 Event            : _KEVENT
   +0x0b0 CompletionContext : (null) 
   +0x0b8 IrpListLock      : 0
   +0x0c0 IrpList          : _LIST_ENTRY [ 0xffffb408`e33ff920 - 0xffffb408`e33ff920 ]
   +0x0d0 FileObjectExtension : (null) 
0: kd> !irp ffffb408e4986010 2
Irp is active with 17 stacks 16 is current (= 0xffffb408e4986518)
 No Mdl: No System Buffer: Thread ffffb408e3bbc080:  Irp stack trace.  
Flags = 00000404
ThreadListEntry.Flink = ffffb408e3bbc6e8
ThreadListEntry.Blink = ffffb408e494e030
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = ffffb408e4986040
UserEvent = ffffdc0079e96898
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000   
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = ffffb408e4986088
Tail.Overlay.Thread = ffffb408e3bbc080
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = ffffb408e4986518
Tail.Overlay.OriginalFileObject = ffffb408e486e080
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
     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_CLEANUP(12), N/A(0)]


            0 e0 ffffb408db5f5030 ffffb408e486e080 fffff80beb582ed0-ffffb408e4b08980 Success Error Cancel 
           \FileSystem\NTFS FLTMGR!FltpPassThroughCompletion
            Args: 00000000 00000000 00000000 00000000
 [IRP_MJ_CLEANUP(12), N/A(0)]
            0  1 ffffb408db1418a0 ffffb408e486e080 00000000-00000000    pending
           \FileSystem\FltMgr
            Args: 00000000 00000000 00000000 00000000

Irp Extension present at 0xffffb408e49865a8:
0: kd> dt nt!_FILE_OBJECT ffffb408e486e080
   +0x000 Type             : 0n5
   +0x002 Size             : 0n216
   +0x008 DeviceObject     : 0xffffb408`daf108a0 _DEVICE_OBJECT
   +0x010 Vpb              : 0xffffb408`db001c80 _VPB
   +0x018 FsContext        : 0xffffa086`7678ac00 Void
   +0x020 FsContext2       : 0xffffa086`75be5570 Void
   +0x028 SectionObjectPointer : 0xffffb408`dab1fdd8 _SECTION_OBJECT_POINTERS
   +0x030 PrivateCacheMap  : (null) 
   +0x038 FinalStatus      : 0n0
   +0x040 RelatedFileObject : (null) 
   +0x048 LockOperation    : 0 ''
   +0x049 DeletePending    : 0x1 ''
   +0x04a ReadAccess       : 0 ''
   +0x04b WriteAccess      : 0 ''
   +0x04c DeleteAccess     : 0x1 ''
   +0x04d SharedRead       : 0x1 ''
   +0x04e SharedWrite      : 0x1 ''
   +0x04f SharedDelete     : 0x1 ''
   +0x050 Flags            : 0x44040
   +0x058 FileName         : _UNICODE_STRING "\Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt~RF5e70000.TMP"
   +0x068 CurrentByteOffset : _LARGE_INTEGER 0x0
   +0x070 Waiters          : 0
   +0x074 Busy             : 0
   +0x078 LastLock         : (null) 
   +0x080 Lock             : _KEVENT
   +0x098 Event            : _KEVENT
   +0x0b0 CompletionContext : (null) 
   +0x0b8 IrpListLock      : 0
   +0x0c0 IrpList          : _LIST_ENTRY [ 0xffffb408`e486e140 - 0xffffb408`e486e140 ]
   +0x0d0 FileObjectExtension : (null)
    · Share on Facebook
  • Dejan_MaksimovicDejan_Maksimovic Member - All Emails Posts: 588
    via Email
    Huh, I never figured out why, but I saw similar issues this year. A Close
    or Cleanup was always involved, the other IO could be any.
    There is always a deadlock, just not visible with !locks sometimes. Not our
    locks, NTFS locls on the file.

    It looks like some combo of file IO can cause it, but I also saw it with
    some AVs only, never with just our filter. Iirc, Avast and Symantec SEP.

    Not directly helpful, but you are not alone.
    We moved some IO in the end, we had no other choice.

    Dejan.
    · Share on Facebook
  • Scott_Noone_(OSR)Scott_Noone_(OSR) Administrator Posts: 3,628

    What status is NTFS raising there?

    1. Do a k
    2. Figure out the frame number for the call to NtfsRaiseStatusInternal
    3. Do a ".frame /c number"
    4. Do a ub

    And I can tell you where to go from there...

    Any chance you can put the dump somewhere? It would be faster than trying to do it over the forum.

    -scott
    OSR

    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187

    @Scott_Noone_(OSR) said:
    What status is NTFS raising there?

    1. Do a k
    2. Figure out the frame number for the call to NtfsRaiseStatusInternal
    3. Do a ".frame /c number"
    4. Do a ub

    And I can tell you where to go from there...

    Any chance you can put the dump somewhere? It would be faster than trying to do it over the forum.

    I asked the customer and unfortunately we are not allowed to share the dump file.

    So it seems like the status is 0xC0000005 = STATUS_ACCESS_VIOLATION:

    3: kd> .frame /c 0n11
0b ffffdc00`7b7231d0 fffff80b`eae8b1ae NTFS!NtfsRaiseStatusInternal+0x6c
rax=0000000000000000 rbx=ffffdc007b723390 rcx=ffffdc007b721c20
rdx=0000000000000000 rsi=0000000000000000 rdi=0000000080000005
rip=fffff80beadb0950 rsp=ffffdc007b7231d0 rbp=0000000000000000
 r8=fffff80beaeec380  r9=ffffdc007b721e80 r10=ffffdc007b722c50
r11=fffff80beae24a88 r12=ffffb408e471daf0 r13=ffffb408e471df68
r14=ffffdc0079e96450 r15=0000000000000000
iopl=0         nv up di pl zr na po nc
cs=0010  ss=0018  ds=0000  es=0000  fs=0000  gs=0000             efl=00000046
NTFS!NtfsRaiseStatusInternal+0x6c:
fffff80b`eadb0950 cc              int     3
3: kd> ub
NTFS!NtfsRaiseStatusInternal+0x49:
fffff80b`eadb092d 8b5310          mov     edx,dword ptr [rbx+10h]
fffff80b`eadb0930 85d2            test    edx,edx
fffff80b`eadb0932 0f886dc20100    js      NTFS!NtfsRaiseStatusInternal+0x1c2c1 (fffff80b`eadccba5)
fffff80b`eadb0938 81ff440000c0    cmp     edi,0C0000044h
fffff80b`eadb093e 0f8417c20100    je      NTFS!NtfsRaiseStatusInternal+0x1c277 (fffff80b`eadccb5b)
fffff80b`eadb0944 897b10          mov     dword ptr [rbx+10h],edi
fffff80b`eadb0947 8b4b10          mov     ecx,dword ptr [rbx+10h]
fffff80b`eadb094a ff15f0d80700    call    qword ptr [NTFS!_imp_ExRaiseStatus (fffff80b`eae2e240)]

    (based on the fact that the EDI is the status value and its content and the rbx+10h both are 0xC0000005)

    · Share on Facebook
  • Dejan_MaksimovicDejan_Maksimovic Member - All Emails Posts: 588
    via Email
    What Rbx and Rdi are you looking at?
    Rdi is 80000005 there and that is a normal error for Ntfs to cause an
    exception on (stupid, but it does).

    It's buffer overflow, quite common code for an Information Query request.
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited September 2022

    @Dejan_Maksimovic said:
    What Rbx and Rdi are you looking at?
    Rdi is 80000005 there and that is a normal error for Ntfs to cause an
    exception on (stupid, but it does).

    It's buffer overflow, quite common code for an Information Query request.

    I apologize, indeed it is a buffer overflow error (0x80000005), i thought rdi was the classic 0xC0000005, seems like I'm going blind.
    So can this be happening because of some sort of loop in the minifilter stack? How can i find who's fault is it? We are following the rules and using FltCreate instead of NtCreate, thus the request should only go below us and not loop back, and i don't see anyone not following the rule on the call stack.

    So do you think this is because of windows running out of kernel stack limit? How can i check if this is what's causing it? Could this error even be related to why the system is freezing?
    I might also try to reduce our altitude below the AV and see if that helps or not.

    · Share on Facebook
  • Dejan_MaksimovicDejan_Maksimovic Member - All Emails Posts: 588
    via Email
    Buffer overflow is COMMON and acceptable return for a Query Infornation
    call (both file info query and directory listing query).
    I don't see how it relates to a stack limit?
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187

    So how can we find the root cause of this problem? The problem still exists. :(

    Is this a bug in chrome.exe or Kaspersky or our driver or..?

    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited July 10

    @Scott_Noone_(OSR) said:
    What status is NTFS raising there?

    1. Do a k
    2. Figure out the frame number for the call to NtfsRaiseStatusInternal
    3. Do a ".frame /c number"
    4. Do a ub

    And I can tell you where to go from there...

    Any chance you can put the dump somewhere? It would be faster than trying to do it over the forum.

    @Dejan_Maksimovic said:
    Buffer overflow is COMMON and acceptable return for a Query Infornation
    call (both file info query and directory listing query).
    I don't see how it relates to a stack limit?

    Considering that it seems like the error code is 0x80000005, can this be caused loop in chrome.exe or..? Anyway I can find the root cause of this?

    · Share on Facebook
  • Dejan_MaksimovicDejan_Maksimovic Member - All Emails Posts: 588
    via Email
    0x80000005 is not a real error, it is handled the way it usually is. It
    just looks strange the first time you see the stack.
    The issue is not there.

    I wish I knew myself what it is, as it got pretty common.
    My experience is that a Close on the file was (almost) always involved, and
    my guess is that some parent folder lock + file lock hierarchy is wrong.
    But that is all I can help with myself.
    · Share on Facebook
  • Scott_Noone_(OSR)Scott_Noone_(OSR) Administrator Posts: 3,628

    If you can't share the dump and can't run DebugView or ProcMon then you need to figure out a new plan of attack...Have you tried reproducing it locally? Also, are you using WPP tracing? If so you can extract your logs from the dump file. Otherwise you can try running !dbgprint on the crash dump, sometimes the last bit of the DbgPrint buffer is available. Maybe something in there useful for you.

    -scott
    OSR

    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited July 15

    @Scott_Noone_(OSR) said:
    If you can't share the dump and can't run DebugView or ProcMon then you need to figure out a new plan of attack...Have you tried reproducing it locally? Also, are you using WPP tracing? If so you can extract your logs from the dump file. Otherwise you can try running !dbgprint on the crash dump, sometimes the last bit of the DbgPrint buffer is available. Maybe something in there useful for you.

    Unfortunately it is not reproducible, it only happens on few particular machines of the customer, and even then it takes hours before it happens again, and there are no useful logs found in WPP tracing or !dbgprint.

    But I am really sure that the root cause of this is related to that Resource @ 0xffffb408e35b8310 and those four threads that are using it. because:

    Resource @ 0xffffb408e35b8310    Exclusively owned
    Contention Count = 11
    NumberOfSharedWaiters = 3
    NumberOfExclusiveWaiters = 1
     Threads: ffffb408e3bbc080-02<*> ffffb408de8d3080-01    ffffb408de8e4080-01    ffffb408e262b040-01<*> 

     Threads Waiting On Exclusive Access:
              ffffb408e36d7800
    1. In the crash dump, the stack of one of the cores indeed ends up in thread ffffb408e3bbc080, which is a chrome.exe thread, and this is the one that is taking the most kernel time out of all the processes (by alot, KernelTime 00:03:28.390). its callstack ends with. :
    nt!KxReleaseQueuedSpinLock+0x23
nt!ExpReleaseResourceForThreadLite+0x1f6
NTFS!NtfsReleaseFcb+0x4b
NTFS!NtfsCommonQueryInformation$fin$0+0x6c
nt!_C_specific_handler+0x18e
nt!RtlpExecuteHandlerForUnwind+0xd
nt!RtlUnwindEx+0x432
nt!_C_specific_handler+0xe2
nt!RtlpExecuteHandlerForException+0xd
nt!RtlDispatchException+0x421
nt!RtlRaiseStatus+0x4e
NTFS!NtfsRaiseStatusInternal+0x6c
NTFS!NtfsCommonQueryInformation+0xbfc
NTFS!NtfsFsdDispatchSwitch+0xcc
NTFS!NtfsFsdDispatchWait+0x40
FLTMGR!FltpQueryInformationFile+0x112
FLTMGR!FltpGetFileName+0x30c
FLTMGR!FltpGetOpenedFileName+0x19
FLTMGR!FltpCallOpenedFileNameHandler+0x2b
FLTMGR!FltpExpandFilePathWorker+0x445
FLTMGR!FltpExpandFilePath+0x1a
FLTMGR!FltpGetNormalizedFileNameWorker+0x112
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x115
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
luafv!LuafvGenerateFileName+0x4c
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x113
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
wcifs!WcGenerateFileName+0x44
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x115
FLTMGR!FltpGetFileNameInformation+0x5e1
FLTMGR!**FltGetFileNameInformation**+0x1b0
klfle+0x610f0      ----> kaspersky
klfle+0x57950     ----> kaspersky
FLTMGR!FltpPerformPreCallbacks+0x2ea
FLTMGR!FltpPassThroughInternal+0x88
FLTMGR!FltpCreate+0x2e1
nt!IopParseDevice+0x168f
nt!ObpLookupObjectName+0x8af
nt!ObOpenObjectByNameEx+0x1dd
nt!IopCreateFile+0x860
nt!IoCreateFileEx+0x115
FLTMGR!FltpCreateFile+0x1cd
FLTMGR!FltCreateFile+0x8d
ourdriver+0x220a    ----> ourdriver

    And this is for a preclose happening on a backup file that we have created in our minifilter (so we have created this file previously, not in this callstack, using a FltCreateFile. Here however we are trying to get some info about the file on disk so we have to first use FltCreateFile to open the file, and we are using share delete/read/write). Our product is a backup system that backs up some files on some particular folders.

    (This is the only meaningful core call stack in the crash dump, and also note that in this time, the system was frozen, so it has to be related to this)

    1. Thread ffffb408e36d7800 is also a chrome.exe thread :
    nt!KiSwapContext+0x76
nt!KiSwapThread+0x17d
nt!KiCommitThreadWait+0x14f
nt!ExpWaitForResource+0x2a8
nt!ExAcquireResourceExclusiveLite+0x27e
NTFS!NtfsAcquireExclusiveFcb+0x78
NTFS!NtfsAcquireFcbWithPaging+0xbd
NTFS!NtfsFindPrefixHashEntry+0xa6a
NTFS!NtfsFindStartingNode+0xa88
NTFS!NtfsCommonCreate+0x43e
NTFS!NtfsCommonCreateCallout+0x1d
nt!KxSwitchKernelStackCallout+0x27
nt!KiSwitchKernelStackContinue
nt!KiExpandKernelStackAndCalloutOnStackSegment+0x241
nt!KiExpandKernelStackAndCalloutSwitchStack+0xa6
nt!KeExpandKernelStackAndCalloutInternal+0x2f
NTFS!NtfsFsdCreate+0x23a
FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x1a6
FLTMGR!FltpCreate+0x2f5
nt!IopParseDevice+0x168f
nt!ObpLookupObjectName+0x8af
nt!ObOpenObjectByNameEx+0x1dd
nt!IopCreateFile+0x860
nt!IoCreateFileEx+0x115
FLTMGR!FltpNormalizeNameFromCache+0x1a6
FLTMGR!FltpExpandShortNames+0xc082
FLTMGR!FltpGetNormalizedDestinationFileName+0x68
FLTMGR!FltGetDestinationFileNameInformation+0x191
klfle+0x207e9   ---> kaspersky

    And inspecting this one, shows that this is also related to another file in the CacheStorage of chrome.

    1. Both the ffffb408de8d3080 and ffffb408de8e4080 threads are related to kaspersky (avf.exe), and both of them have the following call stack:
    nt!KiSwapContext+0x76
nt!KiSwapThread+0x17d
nt!KiCommitThreadWait+0x14f
nt!ExpWaitForResource+0x2a8
nt!ExAcquireResourceSharedLite+0x365
NTFS!NtfsAcquireFcbWithPaging+0x11e
NTFS!NtfsFindPrefixHashEntry+0xa6a
NTFS!NtfsFindStartingNode+0xa88
NTFS!NtfsCommonCreate+0x43e
NTFS!NtfsCommonCreateCallout+0x1d
nt!KxSwitchKernelStackCallout+0x27
nt!KiSwitchKernelStackContinue
nt!KiExpandKernelStackAndCalloutOnStackSegment+0x241
nt!KiExpandKernelStackAndCalloutSwitchStack+0xa6
nt!KeExpandKernelStackAndCalloutInternal+0x2f
NTFS!NtfsFsdCreate+0x23a
FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x1a6
FLTMGR!FltpCreate+0x2f5

    Sadly, I couldn't retrieve any file name from these threads :(, but I bet they are related to some chrome caching file too.

    1. Finally, the thread ffffb408e262b040's call stack is the following, which seems not that important, and it belongs to System process:
    nt!KiSwapContext+0x76
nt!KiSwapThread+0x17d
nt!KiCommitThreadWait+0x14f
nt!ExpWaitForResource+0x2a8
nt!ExAcquireResourceSharedLite+0x365
NTFS!NtfsAcquireScbForLazyWrite+0x1ed
nt!CcWriteBehindInternal+0xa5
nt!ExpWorkerThread+0xe9
nt!PspSystemThreadStartup+0x41
nt!KiStartSystemThread+0x16

    And the following is the content of that resource :

     dt _ERESOURCE 0xffffb408e35b8310 -r1
nt!_ERESOURCE
   +0x000 SystemResourcesList : _LIST_ENTRY [ 0xffffb408`e33caa20 - 0xffffb408`e3ac1a70 ]
      +0x000 Flink            : 0xffffb408`e33caa20 _LIST_ENTRY [ 0xffffb408`e2fff580 - 0xffffb408`e35b8310 ]
      +0x008 Blink            : 0xffffb408`e3ac1a70 _LIST_ENTRY [ 0xffffb408`e35b8310 - 0xffffb408`e3b29330 ]
   +0x010 OwnerTable       : 0xffffb408`e3b2a1a0 _OWNER_ENTRY
      +0x000 OwnerThread      : 0
      +0x008 IoPriorityBoosted : 0y1
      +0x008 OwnerReferenced  : 0y1
      +0x008 IoQoSPriorityBoosted : 0y1
      +0x008 OwnerCount       : 0y00000000000000000000000000000 (0)
      +0x008 TableSize        : 7
   +0x018 ActiveCount      : 0n1
   +0x01a Flag             : 0xf86
   +0x01a ReservedLowFlags : 0x86 ''
   +0x01b WaiterPriority   : 0xf ''
   +0x020 SharedWaiters    : _KWAIT_CHAIN
      +0x000 Head             : _SINGLE_LIST_ENTRY
   +0x028 ExclusiveWaiters : 0xffffb408`dce876d0 _KEVENT
      +0x000 Header           : _DISPATCHER_HEADER
   +0x030 OwnerEntry       : _OWNER_ENTRY
      +0x000 OwnerThread      : 0xffffb408`e3bbc080
      +0x008 IoPriorityBoosted : 0y0
      +0x008 OwnerReferenced  : 0y0
      +0x008 IoQoSPriorityBoosted : 0y1
      +0x008 OwnerCount       : 0y00000000000000000000000000010 (0x2)
      +0x008 TableSize        : 0x14
   +0x040 ActiveEntries    : 1
   +0x044 ContentionCount  : 0xb
   +0x048 NumberOfSharedWaiters : 3
   +0x04c NumberOfExclusiveWaiters : 1
   +0x050 Reserved2        : (null) 
   +0x058 Address          : (null) 
   +0x058 CreatorBackTraceIndex : 0
   +0x060 SpinLock         : 0xffffdc00`7b721c20

    But as I am no an expert in the NTFS and file system in kernel, I can't put all these things together to understand what is causing this system freeze.. !locks output doesn't seem to indicate a deadlock, but it sure as hell seems like it..

    How can I find more info about that resource @ 0xffffb408e35b8310? Anyone has any idea what else can search for in my crash dump to find out the root cause of this?

    As a side note, lowering our minifilter altitude and making ourself go below kaspersky's minifilter solved the issue, but this is not a optimal long term solution, I need to find the reason that this is happening..

    Post edited by brad_H on
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited July 15

    So overall this seems like a NTFS related deadlock on a internal NTFS ERESOURCE, and one weird thing I just found, is that considering that kaspersky (in callstack of thread ffffb408e36d7800) is using FltGetDestinationFileNameInformation, which surely wouldn't write to the file and is a read only operation, then why is NTFS.sys using ExAcquireResourceExclusiveLite, instead of ExAcquireResourceExclusiveLite for that resource? Why would FltGetDestinationFileNameInformation need a exclusive lock ?!!

    · Share on Facebook
  • Dejan_MaksimovicDejan_Maksimovic Member - All Emails Posts: 588
    via Email
    Cool question - a FILE_OPEN request does not need an exclusive lock, IMO.
    Bur FILE_OPEN_IF or any other do, though FltMgr should not be asking that
    type of Disposition.

    Do you have MEX extensions for Windbg? If not, get them from MS's site, and
    run !mex.t on the threads and post it please.
    Long shot, but I wonder exactly what time they spent waiting.
    · Share on Facebook
  • brad_Hbrad_H Member Posts: 187
    edited July 15

    @Dejan_Maksimovic said:
    Cool question - a FILE_OPEN request does not need an exclusive lock, IMO.
    Bur FILE_OPEN_IF or any other do, though FltMgr should not be asking that
    type of Disposition.

    Do you have MEX extensions for Windbg? If not, get them from MS's site, and
    run !mex.t on the threads and post it please.
    Long shot, but I wonder exactly what time they spent waiting.

    Here you go, so indeed this is really related to these chrome cache files. Note that from these three files, we are the one who have created the index.txt.tmp.backup using FltCreateFile (with share read/write/delete) + FltWriteFile. But the other two files are not created by us. Considering that the driver for index.txt.tmp is FltMgr, maybe the minifilter for Kaspersky is the one that has created that file?

    Also as a reminder, in the following call stack which is in the pre close of the index.txt.tmp.backup, we are using FltCreateFile to get the file object corresponding to the file (so we are using FILE_OPEN, with share read/write/delete), so we can get more info related to that file.

    kd> !mex.t 
Process                       Thread                       CID       TEB              UserTime KernelTime ContextSwitches Wait Reason     Time State
chrome.exe (ffffb408e37f5080) ffffb408e3bbc080 (E|K|W|R|V) 294.1ea8  0000009b5739b000     63ms  3m:28.391           26149 WrDispatchInt 1s.046 Running on processor 3

Irp List:
    IRP              File                                                                                                                                                       Driver
    ffffb408e3adc1c0 \Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt.tmp.backup             FltMgr
    ffffb408e494e010 \Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt.tmp                    FltMgr
    ffffb408e4986010 \Users\test\AppData\Local\Google\Chrome\User Data\Default\Service Worker\CacheStorage\cc48a22222f64c442756e922770a3fdedfa75bed\index.txt~RF5e7611.TMP           NTFS


nt!KxReleaseQueuedSpinLock+0x23
nt!ExpReleaseResourceForThreadLite+0x1f6
NTFS!NtfsReleaseFcb+0x4b
NTFS!NtfsCommonQueryInformation$fin$0+0x6c
nt!_C_specific_handler+0x18e
nt!RtlpExecuteHandlerForUnwind+0xd
nt!RtlUnwindEx+0x432
nt!_C_specific_handler+0xe2
nt!RtlpExecuteHandlerForException+0xd
nt!RtlDispatchException+0x421
nt!RtlRaiseStatus+0x4e
NTFS!NtfsRaiseStatusInternal+0x6c
NTFS!NtfsCommonQueryInformation+0xbfe
NTFS!NtfsFsdDispatchSwitch+0xcc
NTFS!NtfsFsdDispatchWait+0x40
FLTMGR!FltpQueryInformationFile+0x112
FLTMGR!FltpGetFileName+0x30c
FLTMGR!FltpGetOpenedFileName+0x19
FLTMGR!FltpCallOpenedFileNameHandler+0x2b
FLTMGR!FltpExpandFilePathWorker+0x445
FLTMGR!FltpExpandFilePath+0x1a
FLTMGR!FltpGetNormalizedFileNameWorker+0x112
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x113
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
luafv!LuafvGenerateFileName+0x4c
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x113
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
wcifs!WcGenerateFileName+0x44
FLTMGR!FltpCallOpenedFileNameHandler+0x89
FLTMGR!FltpGetNormalizedFileNameWorker+0x2f
FLTMGR!FltpGetNormalizedFileName+0x1a
FLTMGR!FltpCreateFileNameInformation+0x32c
FLTMGR!HandleStreamListNotSupported+0x113
FLTMGR!FltpGetFileNameInformation+0x5e7
FLTMGR!FltGetFileNameInformation+0x1b0
klfle+0x610f0
klfle+0x57950
FLTMGR!FltpPerformPreCallbacks+0x2ea
FLTMGR!FltpPassThroughInternal+0x88
FLTMGR!FltpCreate+0x2e1
nt!IopParseDevice+0x168f
nt!ObpLookupObjectName+0x8af
nt!ObOpenObjectByNameEx+0x1dd
nt!IopCreateFile+0x860
nt!IoCreateFileEx+0x115
FLTMGR!FltpCreateFile+0x1cd
FLTMGR!FltCreateFile+0x8d
ourdriver+0x220a
FLTMGR!FltpPerformPreCallbacks+0x2ea
FLTMGR!FltpPassThroughInternal+0x88
FLTMGR!FltpPassThrough+0x1a6
FLTMGR!FltpDispatch+0x9e
nt!IopDeleteFile+0x12d
nt!ObpRemoveObjectRoutine+0x78
nt!ObfDereferenceObject+0xa1
nt!MiSegmentDelete+0x171
nt!MiCheckControlArea+0x147
nt!MmPurgeSection+0x1af
nt!CcPurgeCacheSection+0xcf
NTFS!NtfsDeleteFile+0xe2e
NTFS!NtfsCommonCleanup+0x2b2c
NTFS!NtfsCommonCleanupCallout+0x19
nt!KxSwitchKernelStackCallout+0x27
nt!KiSwitchKernelStackContinue
nt!KiExpandKernelStackAndCalloutOnStackSegment+0x241
nt!KiExpandKernelStackAndCalloutSwitchStack+0xa6
nt!KeExpandKernelStackAndCalloutInternal+0x2f
NTFS!NtfsFsdCleanup+0x268
FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x1a6
FLTMGR!FltpDispatch+0xb6
nt!IopCloseFile+0x150
nt!ObCloseHandleTableEntry+0x245
nt!NtClose+0xcb
nt!KiSystemServiceCopyEnd+0x13
0x7ffd91175ce4
    · Share on Facebook
Sign In or Register to comment.

Howdy, Stranger!

It looks like you're new here. Sign in or register to get started.

Sign In Register
Upcoming OSR Seminars
OSR has suspended in-person seminars due to the Covid-19 outbreak. But, don't miss your training! Attend via the internet instead!
Kernel Debugging 16-20 October 2023 Live, Online
Developing Minifilters 13-17 November 2023 Live, Online
Internals & Software Drivers 4-8 Dec 2023 Live, Online
Writing WDF Drivers 10-14 July 2023 Live, Online

Categories