Score:1

Windows file content not updated in Explorer/Powershell

cf flag

On a Windows Server a logging tool writes .log files to disk continuesly and rotates log files daily at midnight. Every day the new log file gets created, but almost every day its content / meta data does not get updated afterwards in Windows Explorer and Powershell.

Example: A file was created on May 17th, 2022 at 0:00. It has a size of roughly 24KB in Windows Explorer and has a last write time at about midnight (I didn't check the exact time to the second). If I use Powershell

(Get-Item).Length

I get a size of 24401.

Now when I right click the same file the Windows Explorer and inspect its properties it updates the size to 4,593KB and last write time to May 17th, 2022 09:34. The exact time and size does not really matter, but the problem is this: Why is the Windows Explorer and Windows Powershell completeley out of sync with the underlying filesystem like that? What can even cause a discrepancy like this?

Another time I used this to test if the file gets copied out of sync or with the correct content:

Copy-Item ".. source file .." -Destination ".. somewhere .."

the attributes of the original file get updated so I can use that as a really bad workaround to always have the latest version of the file actually available in Powershell as I'm analysing the file with a Powershell script and really need all of its content and not only the content the file had when it was created 9h earlier.

Did anyone ever witness this kind of behaviour in Windows?

  • Filesystem: NTFS
  • OS: Windows Server 2019 Version 1809 Build 17763.2803
  • "Hardware": virtual Server on VMware ESXi Server
Score:0
cn flag

Yes this is because the process is still writing to the file and the buffers are not flushed.

Typically, when you want to write to a file you can (roughly) do something like that:

1. Create/Open a file and retrieve a "channel" (a handle) towards the file
2. Write something
3. Flush the buffer/Close the file "channel" (handle) (=commit to disk)
(then, repeat 1, 2 and 3 when you want to write something again)

However doing something like that is okay if you want to write something once in a while, because "Opening the handle to the file" and "Flushing the buffers" is not "free" when it comes to performance.

This means that if you plan to frequently write to a file, it's better to just Create/Open a file, then Write multiple times, as needed, and when you're done Flush or Close the handle (in my example above this means 1, 2 [repeat step 2 as needed], then, later, 3)

And while the data are not Flushed to disk / committed: you can't rely on them!

Microsoft provides more details about that:

Flushing System-Buffered I/O Data to Disk

[...]Windows stores the data in file read and write operations in system-maintained data buffers to optimize disk performance. When an application writes to a file, the system usually buffers the data and writes the data to the disk on a regular basis[...]

The FlushFileBuffers Windows API doc says:

[...]Typically the WriteFile and WriteFileEx functions write data to an internal buffer that the operating system writes to a disk or communication pipe on a regular basis. The FlushFileBuffers function writes all the buffered information for a specified file to the device or pipe.

Due to disk caching interactions within the system, the FlushFileBuffers function can be inefficient when used after every write to a disk drive device when many writes are being performed separately.[...]

CreateFile documentation:

[...]When an application is finished using the object handle returned by CreateFile, use the CloseHandle function to close the handle. This not only frees up system resources, but can have wider influence on things like sharing the file or device and committing data to disk. Specifics are noted within this topic as appropriate.[...]

More information about File Caching available here, note that:

File system metadata is always cached. Therefore, to store any metadata changes to disk, the file must either be flushed or be opened with FILE_FLAG_WRITE_THROUGH.

So, as you can see, the behavior depends on the design of the application, it's not uncommon to see that log files are only flushed to disk only once in a while for performance reasons and you can't rely on metadata such as date/time, file size, or even file content while the application is still writing to the file.

Johannes B. Latzel avatar
cf flag
I don't think it is the application itself that is the problem here. I tried this to verify the hypothesis: a) I restarted the server (so all file handles get closed or discarded), b) I checked the last write time: stamp from before the time of step a), c) i checked the properties of the file, d) i checked the last write time: stamp from after step a). If it was an application problem writing/flushing its data the metadata after the restart should have already been up-to-date-ish but wasn't.
mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.