Everything sometimes hangs while updating its index

[bryane8341]

I'm running the latest released version (1.4.1.895 (x64)) as a background process, not a service. I've occasionally been seeing behavior as described by a previous user here: viewtopic.php?f=6&t=5843 - Everything has one thread using 100% of the core it's running on and it stops updating its database. No file system changes are detected after this thread seems to get stuck in a loop, but I can still open new Everything windows and search the existing (outdated) database. If I restart Everything, it will be fine for a while until something gets it back into this state.

I enabled the debug log file for Everything and the next time this happened, it logged hundreds of megabytes of "attribute list 00" before I noticed and restarted the process. Leading up to this in the log, it looks like some folders/files were deleted:

2018-09-06 14:10:42.286: remove ntfs folder js with children
2018-09-06 14:10:42.286: remove subfolders and files from js
2018-09-06 14:10:42.286: USN 2018-09-06 14:10:42.286: HARD_LINK_CHANGE 2018-09-06 14:10:42.286: CLOSE 2018-09-06 14:10:42.286: I25F00.tte
...
2018-09-06 14:10:42.286: USN 2018-09-06 14:10:42.286: DELETE 2018-09-06 14:10:42.286: CLOSE 2018-09-06 14:10:42.286: fonts
...
2018-09-06 14:10:42.291: attribute list 00
2018-09-06 14:10:42.291: attribute list 00
2018-09-06 14:10:42.291: parent backup count 0
2018-09-06 14:10:42.291: attribute list 00
2018-09-06 14:10:42.291: attribute list 00
...
2018-09-06 14:10:42.324: attribute list 00
2018-09-06 14:10:42.324: removed 0 subfolders and 36 files from js in 0.038433 seconds
2018-09-06 14:10:42.324: attribute list 00
...
2018-09-06 14:10:42.325: attribute list 00
2018-09-06 14:10:42.325: remove ntfs folder css with children
2018-09-06 14:10:42.325: remove subfolders and files from css
2018-09-06 14:10:42.325: attribute list 00
..
2018-09-06 14:10:42.348: attribute list 00
2018-09-06 14:10:42.348: removed 0 subfolders and 2 files from css in 0.023237 seconds
2018-09-06 14:10:42.348: attribute list 00
...
2018-09-06 14:10:42.348: attribute list 00
2018-09-06 14:10:42.348: remove ntfs folder js with children
2018-09-06 14:10:42.348: remove subfolders and files from js
2018-09-06 14:10:42.348: attribute list 00

Once the "attribute list 00" flood starts, there are some lines intermittently showing other stuff happening, but the vast majority of the lines logged are just the same line about the attribute list. I looked at Everything in Process Explorer and saw that the only CPU usage was a single thread maxing out one core. I took some samples of the stack for this thread to get you some idea of where it seems to be running:

ntoskrnl.exe!KiCpuId+0xaa
ntoskrnl.exe!ExReleaseResourceAndLeaveCriticalRegion+0x212
ntoskrnl.exe!KeWaitForMutexObject+0x1a3
ntoskrnl.exe!ExReleaseResourceForThreadLite+0xb8
ntoskrnl.exe!KeSetTimer+0x7e1
ntoskrnl.exe!KiCpuId+0x2533
ntoskrnl.exe!CcCopyRead+0x515
ntoskrnl.exe!NtQueryVolumeInformationFile+0x1249
ntoskrnl.exe!NtFsControlFile+0x56
ntoskrnl.exe!longjmp+0x5c63
ntdll.dll!NtFsControlFile+0xa
KERNELBASE.dll!OpenThread+0xa8
kernel32.dll!DeviceIoControl+0x7f
Everything.exe+0xcfff0
Everything.exe+0x4b3f8
Everything.exe+0x4ccc2
Everything.exe+0xdfa21
kernel32.dll!BaseThreadInitThunk+0xd
ntdll.dll!RtlUserThreadStart+0x1d

ntoskrnl.exe!KiCpuId+0xaa
ntoskrnl.exe!ExReleaseResourceAndLeaveCriticalRegion+0x212
ntoskrnl.exe!KeWaitForMutexObject+0x1a3
ntoskrnl.exe!ExReleaseResourceForThreadLite+0xb8
ntoskrnl.exe!KeSetTimer+0x7e1
ntoskrnl.exe!KiCheckForKernelApcDelivery+0x25
Ntfs.sys+0xba3c2
fltmgr.sys!FltIsCallbackDataDirty+0x2df
fltmgr.sys!FltDeletePushLock+0x50e
fltmgr.sys!FltIsCallbackDataDirty+0x2df
fltmgr.sys!FltDeletePushLock+0x50e
ntoskrnl.exe!CcCopyRead+0x4aa
ntoskrnl.exe!NtQueryVolumeInformationFile+0x1249
ntoskrnl.exe!NtFsControlFile+0x56
ntoskrnl.exe!longjmp+0x5c63
ntdll.dll!NtFsControlFile+0xa
KERNELBASE.dll!OpenThread+0xa8
kernel32.dll!DeviceIoControl+0x7f
Everything.exe+0xcfff0
Everything.exe+0x4b3f8
Everything.exe+0x4ccc2
Everything.exe+0xdfa21
kernel32.dll!BaseThreadInitThunk+0xd
ntdll.dll!RtlUserThreadStart+0x1d

ntoskrnl.exe!KiCpuId+0xaa
ntoskrnl.exe!ExReleaseResourceAndLeaveCriticalRegion+0x212
ntoskrnl.exe!KeWaitForMutexObject+0x1a3
ntoskrnl.exe!ExReleaseResourceForThreadLite+0xb8
ntoskrnl.exe!KeSetTimer+0x7e1
ntoskrnl.exe!KiCheckForKernelApcDelivery+0x25
fltmgr.sys!FltAcquirePushLockShared+0x2ab
fltmgr.sys!FltIsCallbackDataDirty+0xa67
fltmgr.sys!FltDeletePushLock+0x4f2
fltmgr.sys!FltIsCallbackDataDirty+0x2df
fltmgr.sys!FltDeletePushLock+0x50e
ntoskrnl.exe!CcCopyRead+0x4aa
ntoskrnl.exe!NtQueryVolumeInformationFile+0x1249
ntoskrnl.exe!NtFsControlFile+0x56
ntoskrnl.exe!longjmp+0x5c63
ntdll.dll!NtFsControlFile+0xa
KERNELBASE.dll!OpenThread+0xa8
kernel32.dll!DeviceIoControl+0x7f
Everything.exe+0xcfff0
Everything.exe+0x4b3f8
Everything.exe+0x4ccc2
Everything.exe+0xdfa21
kernel32.dll!BaseThreadInitThunk+0xd
ntdll.dll!RtlUserThreadStart+0x1d

ntoskrnl.exe!KiCpuId+0xaa
ntoskrnl.exe!ExReleaseResourceAndLeaveCriticalRegion+0x212
ntoskrnl.exe!KeWaitForMutexObject+0x1a3
ntoskrnl.exe!ExReleaseResourceForThreadLite+0xb8
ntoskrnl.exe!KeSetTimer+0x7e1
ntoskrnl.exe!KiCheckForKernelApcDelivery+0x25
ntoskrnl.exe!ObReferenceObjectByHandleWithTag+0x3ce
ntoskrnl.exe!ObReferenceObjectByHandle+0x25
ntoskrnl.exe!NtQueryVolumeInformationFile+0x75b
ntoskrnl.exe!NtFsControlFile+0x56
ntoskrnl.exe!longjmp+0x5c63
ntdll.dll!NtFsControlFile+0xa
KERNELBASE.dll!OpenThread+0xa8
kernel32.dll!DeviceIoControl+0x7f
Everything.exe+0xcfff0
Everything.exe+0x4b3f8
Everything.exe+0x4ccc2
Everything.exe+0xdfa21
kernel32.dll!BaseThreadInitThunk+0xd
ntdll.dll!RtlUserThreadStart+0x1d

Hopefully this is helpful. Let me know if there's anything else I can do to help with this. If the full debug log files would help (I captured logs when this happened a couple times), let me know and I can email them to you - it's about 3MB total when compressed with 7z. Thank you!

[void]

Thanks for the debug info, bryane8341.

Could you please try Everything 1.4.1.913?

I've added detection for circular references in attribute lists, which I think might be causing the issue you described.

[bryane8341]

Thank you! I'll give that a try when I'm back at work on Monday. I should know within a day or two if I see another hang or not, and I'll let you know.

[bryane8341]

Looks like that may have fixed it. Here's what I see in the logs now when it encounters "attribute list 00":

2018-09-10 11:53:29.012: attribute list 00
2018-09-10 11:53:29.012: _NTFS_ATTRIBUTE_TYPE_DATA in 00040000000fe422
2018-09-10 11:53:29.012: retry with type_data 00040000000fe422 for 0037000000059bc3
2018-09-10 11:53:29.012: got ntfs file record 40000000fe422 3493876 3
2018-09-10 11:53:29.012: attribute list 00
2018-09-10 11:53:29.012: _NTFS_ATTRIBUTE_TYPE_DATA in 00040000000feea2
2018-09-10 11:53:29.012: retry with type_data 00040000000feea2 for 0031000000059bc4
2018-09-10 11:53:29.012: got ntfs file record 40000000feea2 3308760 3
2018-09-10 11:53:29.012: attribute list 00
2018-09-10 11:53:29.012: _NTFS_ATTRIBUTE_TYPE_DATA in 00040000000feea3
2018-09-10 11:53:29.012: retry with type_data 00040000000feea3 for 002a000000059bc5
2018-09-10 11:53:29.012: got ntfs file record 40000000feea3 2254428 3
2018-09-10 11:53:29.012: attribute list 00
2018-09-10 11:53:29.012: _NTFS_ATTRIBUTE_TYPE_DATA in 002b00000004d9e1
2018-09-10 11:53:29.012: retry with type_data 002b00000004d9e1 for 000c00000014f5e0
2018-09-10 11:53:29.012: got ntfs file record 2b00000004d9e1 450336 3
2018-09-10 11:53:29.012: FRN not in use 19000000204e6f
2018-09-10 11:53:29.012: got ntfs file record 19000000204e6f 18446744073709551615 0
2018-09-10 11:53:29.012: FRN not in use 90000002412c3
2018-09-10 11:53:29.012: got ntfs file record 90000002412c3 18446744073709551615 0
2018-09-10 11:53:29.012: updated fd for All in 0.000001 seconds

And it continues on with plenty of other stuff. So instead of going into an infinite loop on the "attribute list 00", it's moving on and still seems to be updating its database. I'll let you know if I see another hang or anything else weird, but so far at least this looks great! Thank you for such a quick response, and let me know if there's anything else you'd like me to do.

[void]

Thanks for the debug log.

This would confirm a NTFS record attribute list with a base FRN that ends up pointing to another record, which also points back to the original record (circular reference).

The fix in 913 simply ignores the NTFS record when a circular reference is detected.

If you search for:
size:unknown
Everything should list this file.

This should never occur, so I would recommend checking this disk for errors:

• Please backup anything important on your drive before checking it for errors.
• In Windows Explorer, right click your drive and click Properties.
• Click the Tools tab.
• Click Check now...
• Click Start
• If prompted to schedule a scan on the next restart, click Yes.

[bryane8341]

Interesting. I searched for "size:unknown" and it showed two files: "D:\temp\Everything Debug Log.txt" and a .pack file in one of the git repos I use for work. I quit and restarted Everything and did the same search again and it turned up the same two files. Then I quit Everything again, deleted Everything.db, and restarted Everything. It scanned my disks and when it was done I did the same search, but this time it didn't turn up any files. Searching for the debug log, which previously did show a blank size in Everything when I searched for it, it now shows the actual size. So I wonder if instead of something being wrong with my disk, something happened to cause Everything to incorrectly write the sizes of those files into its database?

After the above stuff happened, I ran a script to do some cleanup on my git repos (gc, etc.) After that finished, I tried searching for "size:unknown" in Everything again just for kicks. This time, it turned up several .pack files from my repos. Then I quit Everything, moved Everything.db to another folder, and restarted Everything. Again, after it scanned my drives to build the database, the previously unknown-size files no longer had unknown sizes.

I then tried quitting Everything, replacing the previous (bad?) Everything.db file I had moved out earlier, and restarting Everything. I expected it might show the same unknown-size files, but as Everything was starting up, it re-scanned my disks and no longer showed them as unknown. However, if I disable "Monitor changes" for my disks in Everything settings and start it up with this bad copy of the .db, it seems to just load the db as-is without updating it. When I do this, I can still see the unknown-size files in Everything. Re-enabling the "Monitor changes" option after I have loaded the bad .db results in the unknown-size files going away again.

Hopefully this makes some sense to you or offers insights into what might be going on. Does it sound like there might be more going on here than some corruption on my disk? It seems that way to me since the unknown-size files don't appear as unknown when Everything does a clean scan - they only seem to show up while Everything is already running and processing changes as they are occurring live (i.e., if there is file corruption, it doesn't seem to persist in a way that Everything can detect from a fresh scan). Is there any more I can try that might provide you with useful information?

I will try running chkdsk tonight when I can reboot and let the computer scan overnight to see if it turns up anything. Thank you!

[void]

This issue is most likely related to this issue.

Please see if Everything 1.4.1.914 helps.

Usually Everything will only update file sizes when all handles to the file are closed. So it is common to see file sizes of 0 for logs files.
However, unknown sizes is a different issue.

I then tried quitting Everything, replacing the previous (bad?) Everything.db file I had moved out earlier, and restarting Everything. I expected it might show the same unknown-size files, but as Everything was starting up, it re-scanned my disks and no longer showed them as unknown. However, if I disable "Monitor changes" for my disks in Everything settings and start it up with this bad copy of the .db, it seems to just load the db as-is without updating it. When I do this, I can still see the unknown-size files in Everything. Re-enabling the "Monitor changes" option after I have loaded the bad .db results in the unknown-size files going away again.

Another easier way to do this would be to run Everything with the -read-only command line option and the -db command line option, eg:
Everything.exe -db "c:\backup\old everything.db" -read-only
Note: this will only work when Everything is not already running.

[bryane8341]

Ah, thanks! I'll give that new version a try, and thanks for the tip on the read-only mode.

Here is the output from the chkdisk run:

Checking file system on D:
The type of the file system is NTFS.
Volume label is Data.


A disk check has been scheduled.
Windows will now check the disk.

CHKDSK is verifying files (stage 1 of 3)...
5885952 file records processed. File verification completed.
6088 large file records processed. 0 bad file records processed. 0 EA records processed. 1421 reparse records processed. CHKDSK is verifying indexes (stage 2 of 3)...
6715338 index entries processed. Index verification completed.
0 unindexed files scanned. 0 unindexed files recovered. CHKDSK is verifying security descriptors (stage 3 of 3)...
5885952 file SDs/SIDs processed. Cleaning up 240 unused index entries from index $SII of file 0x9.
Cleaning up 240 unused index entries from index $SDH of file 0x9.
Cleaning up 240 unused security descriptors.
Security descriptor verification completed.
414694 data files processed. CHKDSK is verifying Usn Journal...
34034704 USN bytes processed. Usn Journal verification completed.
CHKDSK discovered free space marked as allocated in the
master file table (MFT) bitmap.
Windows has made corrections to the file system.

500105215 KB total disk space.
223001400 KB in 2778155 files.
1403132 KB in 414695 indexes.
0 KB in bad sectors.
6001547 KB in use by the system.
65536 KB occupied by the log file.
269699136 KB available on disk.

4096 bytes in each allocation unit.
125026303 total allocation units on disk.
67424784 allocation units available on disk.

After a little googling, it doesn't sound like the errors it fixed are that scary - probably junk left around after an unexpected reboot, etc. Does any of that sound like it might be related to what I was seeing?

I'll let you know if I notice any more unknown-size files. Thank you!

[void]

The errors are nothing to be concerned about. $SII is the Security ID index file, it is private NTFS file and is ignored by Everything.
It is unrelated to the issue you described.

The unknown size problem is most likely an issue with Everything that should be resolved in Everything 1.4.1.914.

[bryane8341]

Thanks! I don't know if 914 has made a difference to this particular issue. I'm still occasionally seeing unknown-size items show up in Everything when I try searching for them, but after I restart Everything and it updates its database, they are no longer unknown.

This really isn't a problem for me; I rarely need to search/sort by file size, so having a small handful of files (if any) with unknown sizes doesn't bother me. The hangs that I started this thread about seem to have been completely fixed since version 913, so I'm happy.

However, I'm happy to assist in tracking this down further if you'd like to spend the time, since I seem to have an environment that reproduces the problem. Is there anything I can do to help or would you like to let this unknown-size issue go for now?

[void]

It would be greatly appreciated if you could please run Everything with debug logging:

• In Everything, type in the following search and press ENTER:
  /debug_log
• Wait for a file with an unknown size to show up.
• Please send your %TEMP%\Everything Debug Log.txt to support@voidtools.com

Note: you will need to re-enable debug logging every time you start Everything.

[bryane8341]

I might have to retract my previous statement. I've been checking for unknown-size files periodically, but haven't seen any in the last week. I will let you know if I do see any more, and I'll send in logs. Thanks for all the help and the quick fixes!