VirtualStore inconsistency?

[hsgoogol]

Here is my scenario:

- Two computers running Windows Vista. Both HP computers, with OEM
Vista. One is a laptop.

- I have a program, legacy (older) software, that I installed on
each. On one, it just exits if you run it. On the other, it runs
fine.

- I did some digging, using SysInternals ProcMon to monitor registry
and file I/O. I tracked down the point where the one computer fails.
After opening a file, it attempts to read, and the next monitored
event shows it exiting its thread and then cleaning up.

- I narrowed it down to the call to CreateFile(). It is attempting to
open a file inside c:\Program Files. I know that Vista should not
allow this.

- Actually, it's only opening it for Read. So should it be allowed?

- On one computer, it gets a response of "OpenResult: Superseded".
ProcMon shows the result as "Reparse". In the next line, ProcMon
shows it opening the "Compatibility file" inside VirtualStore. This
is what should happen. All goes well after that.

- On the other computer, the call to CreateFile() gets a response of
"OpenResult: Opened". ProcMon shows the result as "Success". Why?
When it attempts to read shortly after this, it fails. I guess it
never really opened the file, but why did CreateFile() return Opened?
Or, if reads are allowed in Program Files, why did the read fail?

- It's possible that the 2 computers have different levels of Windows
Updates, but I think that shouldn't make a difference.

Any ideas?

I saved the ProcMon output as csv files, and will post them in the
next post. There might be useful details in there.

 

[hsgoogol]

Here are the 2 csv files from the 2 ProcMon sessions from the 2
computers.  The interesting part is the first CreateFile() in each
one.To read these more clearly, paste these into Notepad, save as
text, rename the file as .csv, and open (in Excel).  Resize the
columns by selecting all columns, and choosing menu Format-Column-
Autofit.=============================="Sequence","Time of
Day","Process
Name","PID","Operation","Path","Result","Detail""0","3:12:48.8036726
PM","zexplore.exe","5268","CreateFile","C:\Program Files\Davka\It's
About Time\locbase.dat","SUCCESS","Desired Access: Generic Read,
Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory
File, Attributes: N, ShareMode: Read, AllocationSize: n/a, OpenResult:
Opened""1","3:12:48.8042944
PM","zexplore.exe","5268","QueryBasicInformationFile","C:\Program Files
\Davka\It's About Time\locbase.dat","SUCCESS","CreationTime:
11/01/2008 5:10:53 PM, LastAccessTime: 11/01/2008 5:10:53 PM,
LastWriteTime: 11/09/2000 4:54:00 PM, ChangeTime: 30/01/2008 7:40:29
AM, FileAttributes: N""2","3:12:48.8043191
PM","zexplore.exe","5268","QueryStandardInformationFile","C:\Program
Files\Davka\It's About Time\locbase.dat","SUCCESS","AllocationSize: 0,
EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory:
False""3","3:12:48.8045049 PM","zexplore.exe","5268","QueryOpen","C:
\Program Files\Davka\It's About Time\locbase.dat","FAST IO
DISALLOWED","""4","3:12:48.8046539
PM","zexplore.exe","5268","CreateFile","C:\Program Files\Davka\It's
About Time\locbase.dat","SUCCESS","Desired Access: Read Attributes,
Disposition: Open, Options: Open Reparse Point, Attributes: n/a,
ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult:
Opened""5","3:12:48.8051030
PM","zexplore.exe","5268","QueryBasicInformationFile","C:\Program Files
\Davka\It's About Time\locbase.dat","SUCCESS","CreationTime:
11/01/2008 5:10:53 PM, LastAccessTime: 11/01/2008 5:10:53 PM,
LastWriteTime: 11/09/2000 4:54:00 PM, ChangeTime: 30/01/2008 7:40:29
AM, FileAttributes: N""6","3:12:48.8051237
PM","zexplore.exe","5268","CloseFile","C:\Program Files\Davka\It's
About Time\locbase.dat","SUCCESS","""8","3:12:48.8052366
PM","zexplore.exe","5268","ReadFile","C:\Program Files\Davka\It's
About Time\locbase.dat","END OF FILE","Offset: 0, Length: 4,096,
Priority: Normal""12867","3:12:52.4396134
PM","zexplore.exe","5268","Thread Exit","","SUCCESS","User Time:
0.0000000, Kernel Time:
0.0000000"=============================="Sequence","Time of
Day","Process
Name","PID","Operation","Path","Result","Detail""5641","3:21:23.5004171
PM","zexplore.exe","5260","CreateFile","C:\Program Files\Davka\It's
About Time\locbase.dat","REPARSE","Desired Access: Generic Read,
Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory
File, Attributes: N, ShareMode: Read, AllocationSize: n/a, OpenResult:
Superseded""5642","3:21:23.5006062
PM","zexplore.exe","5260","CreateFile","C:\Users\Ruth\AppData\Local
\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","Desired Access: Generic Read, Disposition:
Open, Options: Synchronous IO Non-Alert, Non-Directory File,
Attributes: N, ShareMode: Read, AllocationSize: n/a, OpenResult:
Opened""5643","3:21:23.5007242
PM","zexplore.exe","5260","QueryBasicInformationFile","C:\Users\Ruth
\AppData\Local\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","CreationTime: 06/01/2008 8:46:45 AM,
LastAccessTime: 06/01/2008 8:46:45 AM, LastWriteTime: 06/01/2008
10:23:48 PM, ChangeTime: 01/02/2008 2:44:04 AM, FileAttributes: A
0x10000""5644","3:21:23.5007349
PM","zexplore.exe","5260","QueryStandardInformationFile","C:\Users\Ruth
\AppData\Local\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","AllocationSize: 40,960, EndOfFile: 40,745,
NumberOfLinks: 1, DeletePending: False, Directory:
False""5645","3:21:23.5008242 PM","zexplore.exe","5260","QueryOpen","C:
\Program Files\Davka\It's About Time\locbase.dat","FAST IO
DISALLOWED","""5646","3:21:23.5008924
PM","zexplore.exe","5260","CreateFile","C:\Program Files\Davka\It's
About Time\locbase.dat","REPARSE","Desired Access: Read Attributes,
Disposition: Open, Options: Open Reparse Point, Attributes: n/a,
ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult:
Superseded""5647","3:21:23.5010007
PM","zexplore.exe","5260","QueryOpen","C:\Users\Ruth\AppData\Local
\VirtualStore\Program Files\Davka\It's About Time\locbase.dat","FAST
IO DISALLOWED","""5648","3:21:23.5010655
PM","zexplore.exe","5260","CreateFile","C:\Users\Ruth\AppData\Local
\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","Desired Access: Read Attributes, Disposition:
Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read,
Write, Delete, AllocationSize: n/a, OpenResult:
Opened""5649","3:21:23.5011049
PM","zexplore.exe","5260","QueryBasicInformationFile","C:\Users\Ruth
\AppData\Local\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","CreationTime: 06/01/2008 8:46:45 AM,
LastAccessTime: 06/01/2008 8:46:45 AM, LastWriteTime: 06/01/2008
10:23:48 PM, ChangeTime: 01/02/2008 2:44:04 AM, FileAttributes: A
0x10000""5650","3:21:23.5011147
PM","zexplore.exe","5260","CloseFile","C:\Users\Ruth\AppData\Local
\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","""5652","3:21:23.5011672
PM","zexplore.exe","5260","ReadFile","C:\Users\Ruth\AppData\Local
\VirtualStore\Program Files\Davka\It's About Time
\locbase.dat","SUCCESS","Offset: 0, Length: 4,096, Priority:
Normal""5654","3:21:23.5012702 PM","zexplore.exe","5260","ReadFile","C:
\Users\Ruth\AppData\Local\VirtualStore\Program Files\Davka\It's About
Time\locbase.dat","SUCCESS","Offset: 4,096, Length:
4,096""5656","3:21:23.5013255 PM","zexplore.exe","5260","ReadFile","C:
\Users\Ruth\AppData\Local\VirtualStore\Program Files\Davka\It's About
Time\locbase.dat","SUCCESS","Offset: 8,192, Length:
4,096""5658","3:21:23.5013762 PM","zexplore.exe","5260","ReadFile","C:
\Users\Ruth\AppData\Local\VirtualStore\Program Files\Davka\It's About
Time\locbase.dat","SUCCESS","Offset: 12,288, Length:
4,096""5660","3:21:23.5014266 PM","zexplore.exe","5260","ReadFile","C:
\Users\Ruth\AppData\Local\VirtualStore\Program Files\Davka\It's About
Time\locbase.dat","SUCCESS","Offset: 16,384, Length:
4,096""5662","3:21:23.5014789 PM","zexplore.exe","5260","ReadFile","C:
\Users\Ruth\AppData\Local\VirtualStore\Program Files\Davka\It's About
Time\locbase.dat","SUCCESS","Offset: 20,480, Length:
4,096"==============================