The Case of the Failed File Compression
The other day Bryce tried to use Explorer’s
Send To Compressed (zipped) Folder
feature, seen below, to package up his latest
Process Monitor
source code updates to send me.
Instead of presenting compression progress dialog followed by an opportunity to edit the name of resulting compressed file, Explorer aborted the compression with this error:
Bryce was perplexed. The error didn’t seem to make any sense because he obviously had read permission to the files in the selection, which he’d just finished editing, and compressing files shouldn’t involve some kind of search that could result in a file not being found.
He retried the compression operation, but got the same error, this time after a different number of files had finished compressing.
I happened to walk into his office at this point and he showed me the behavior by trying a few more times, all with the same outcome.
Now both of us were perplexed. It was time to investigate, and the tool we called on for the job was, somewhat ironically, Process Monitor.
We launched Process Monitor, reproduced the failure, stopped the capture, and scanned through the thousands of operations in the trace looking for errors. We saw a slew of NOT FOUND errors near the start of the log, which are the generally innocuous result of an application checking for the pre-existence of a file. In fact, there were literally hundreds of them near the beginning of the log, all of which were queries for the file into which the compressed files would be placed:
That was disturbing, but not directly related to our troubleshooting effort, so I filed it away to look at later.
Several hundred events into the trace later we came across a SHARING VIOLATION error that bore a closer look:
When a process opens a file it can specify if and how it wants to share the file with other processes while it has the file opened. The three types of sharing are read, write and delete, and each is represented with a flag that a process passes to the CreateFile API. In the operation that failed, Explorer didn’t pass any of the flags, indicating that it didn’t want to share the file, as seen in the ShareMode field:
For an open to succeed, the sharing mode of the opener must be compatible with the sharing allowed by a process that already has the file opened, so the explanation for the error was that another process already had the file opened.
Looking back at the trace, the open operation immediately preceding the one with the error is an open of the same file by a process named Inort.exe. Inort’s close of the file isn’t visible in the screenshot because it comes long after Explorer’s failed attempt to open the file. That confirmed that Explorer’s unwillingness to share the file conflicted with Inort having the file open, despite the fact that Inort specified read, write and delete sharing in its open of the file.
Process Monitor had closed another case: Inort holding the file open when Explorer tried to open it was the cause of the sharing violation and almost certainly the reason for the misleading error message. Next we had to identify Inort so that we could come up with a fix or workaround. Process Monitor also answered that question with its image tooltip:
eTrust, Computer Associates’ Antivirus scanner, was apparently opening the file to scan it for viruses, but interfering with the operation of Explorer. Antivirus should be invisible to the system, so the error revealed a bug in eTrust. The workaround was for Bryce to set a directory filter that excludes his source directories from real-time scanning.
I couldn’t reproduce the error when I went back to my office, so I suspected that I had a different version of Inoculan on my system than Bryce. Process Monitor’s process page on the event properties dialog for an Inort.exe event showed that Bryce had version 7.01.0192.0001 and I had the more recent 7.01.0501.000:
Why we have different versions isn’t clear since we’re both using images deployed and managed by Microsoft IT, but it appears that Computer Associates has fixed the bug in newer releases.
Now I turned my attention back to the inefficiencies of Explorer’s compression feature. I captured a Process Monitor trace of the compression of a single file and counted the associated operations. Just for this simple case, Explorer opened the target ZIP file 14 times, 12 of those before it had actually created the file and therefore with NOT FOUND results, and performed directory look ups of the target 19 times. It was also redundant with the source file, opening it 28 times and querying the file’s basic properties 17 times. It’s not like Explorer doesn’t give eTrust plenty of opportunities to cause sharing problems.
In order to verify that Explorer itself was at fault, and not some third-party extension, I looked at the stacks of various events by selecting the event and typing Ctrl+K to open the event properties dialog to the stack page:
Zipfldr.dll, the Explorer file compression DLL, was in most of the stack traces, meaning that the compression engine itself was ultimately responsible for the waste. Further, the number of repetitious operations explodes when you compress multiple files. There are clearly easy ways to improve the algorithm, so hopefully we’ll see a more efficient compression engine in Windows 7.
Update: I've learned that the compression engine has been updated in Vista SP1 to perform fewer file operations.
On a closing note, if you’d like to catch me at my next public speaking engagement, come to
Wintellect’s Devscovery
conference in Redmond, August 14-16, where I’m delivering a keynote on Vista kernel changes.