[wix-users] Files Held In Use Are Deleted After Reboot

Tue Aug 20 16:47:25 PDT 2019

It's timing. The file could not be renamed while the uninstall was happening, but later on the files were able to be overwritten (but by then the files were "scheduled" to be removed at system initialization).

If you are able to do late (instead of early) scheduling of RemoveExistingProducts this issue is less likely to occur (if the file can't be overwritten, two entries per file are scheduled for system initialization: removing the old file and moving a copy of the new file into place). Otherwise you will need to find ways to stop whatever is hard-locking those files before the removal operation calls the DeleteFiles action.

Get Outlook for Android<https://aka.ms/ghei36>
________________________________
From: wix-users <wix-users-bounces at lists.wixtoolset.org> on behalf of Edwin Castro via wix-users <wix-users at lists.wixtoolset.org>
Sent: Tuesday, August 20, 2019 2:31:26 PM
To: WiX Toolset Users Mailing List <wix-users at lists.wixtoolset.org>
Cc: Edwin Castro <egcastr at gmail.com>
Subject: [wix-users] Files Held In Use Are Deleted After Reboot

This is a Windows Installer question. I'm hoping the experts here can help
guide me. Is there a better place I should ask this question?

I am troubleshooting a verbose log for a major upgrade started with
REBOOT=ReallySuppress. RemoveExistingProducts is scheduled immediately
after InstallInitialize. A number of files are identified as held in use
during InstallValidate but are typically no longer in use when they are
removed/copied. However, I see two files that cannot be deleted during
uninstall and are scheduled to be deleted at reboot. Later it appears the
files are successfully copied to their target locations during the install
of the new version. Later, the machine is rebooted and the files are
deleted during reboot causing the application to break.

Below I have verbose log snippets showing this behavior. Names have been
changed below to protect the innocent/guilty.

-------------------
File #1

RemoveDuplicateFiles attempts to delete one file and it appears it tried to
move the file to C:\Config.Msi but perhaps failed to do so and as a result
it just schedules the original file to be deleted at reboot.

MSI (s) (34:18) [01:26:47:634]: Executing op:
SetTargetFolder(Folder=C:\Program Files\Company\Product\x86\)
MSI (s) (34:18) [01:26:47:634]: Executing op:
FileRemove(,FileName=component1.dll,,)
MSI (s) (34:18) [01:26:47:634]: Verifying accessibility of file:
component1.dll
MSI (s) (34:18) [01:26:47:634]: Verifying accessibility of file:
component1.dll
MSI (s) (34:18) [01:26:47:634]: Using source file security for destination.
MSI (s) (34:18) [01:26:47:634]: Note: 1: 2318 2: C:\Config.Msi\85833f1a.rbf
MSI (s) (34:18) [01:26:47:634]: Note: 1: 2329 2: 32 3: C:\Program
Files\Company\Product\x86\component1.dll
MSI (s) (34:18) [01:26:47:634]: Verifying accessibility of file:
component1.dll
MSI (s) (34:18) [01:26:47:634]: Note: 1: 2318 2:
MSI (s) (34:18) [01:26:47:634]: Note: 1: 2318 2:
...
Info 1903.Scheduling reboot operation: Deleting file C:\Program
Files\Company\Product\x86\component1.dll. Must reboot to complete operation.

Normally, I expect for the *.rbf file to be created in C:\Config.Msi\ and
deleted at reboot. But it seems like this didn't happen in this case.
Instead it seems the file was still in place when the new file was copied.
There is no indication if the file was moved and there is no indication
that the file on disk was actually overwritten.

MSI (s) (34:64) [01:26:57:384]: Executing op:
SetSourceFolder(Folder=C:\Program Files\Company\Product\x86\)
MSI (s) (34:64) [01:26:57:384]: Executing op:
SetTargetFolder(Folder=C:\Program Files\Company\Product\x86\)
MSI (s) (34:64) [01:26:57:384]: Executing op:
FileCopy(SourceName=component1.bin,,DestName=component1.dll,Attributes=16384,FileSize=779008,PerTick=0,IsCompressed=0,VerifyMedia=0,,,,,CheckCRC=0,Version=65535.0.0.0,Language=1033,InstallMode=262144,,,,,,,)
MSI (s) (34:64) [01:26:57:384]: File: C:\Program
Files\Company\Product\x86\component1.dll; Overwrite; Won't patch; Existing
file is a lower version
MSI (s) (34:64) [01:26:57:384]: Source for file 'component1.bin' is
uncompressed, at 'C:\Program Files\Company\Product\x86\'.
MSI (s) (34:64) [01:26:57:384]: Re-applying security from existing file.
MSI (s) (34:64) [01:27:01:072]: Product: Product Name. The file C:\Program
Files\Company\Product\x86\component1.dll is being used by the following
process: Name: proc , Id 1128.
...
MSI (s) (34:64) [01:27:01:072]: Verifying accessibility of file:
component1.dll
MSI (s) (34:64) [01:27:01:088]: Note: 1: 2318 2:
MSI (s) (34:64) [01:27:01:088]: Note: 1: 2318 2:
MSI (s) (34:64) [01:27:01:088]: Note: 1: 2318 2: C:\Program
Files\Company\Product\x86\component1.dll
MSI (s) (34:64) [01:27:01:088]: File will have security applied from OpCode.
Info 1603.The file C:\Program Files\Company\Product\x86\component1.dll is
being held in use.  Close that application and retry.

I suppose I can infer that it was able to move the file because error 2318
tells me C:\Program Files\Company\Product\x86\component1.dll does not exist
and presumably it is able to copy the file.

-------------------
File #2

We see very similar behavior with this second file. The *.rbf files does
not exist and the original seems to be scheduled to be deleted at reboot.

MSI (s) (34:18) [01:26:47:884]: Executing op:
FileRemove(,FileName=component2.dll,,ComponentId={GUID})
MSI (s) (34:18) [01:26:47:884]: Verifying accessibility of file:
component2.dll
MSI (s) (34:18) [01:26:47:884]: Verifying accessibility of file:
component2.dll
MSI (s) (34:18) [01:26:47:884]: Using source file security for destination.
MSI (s) (34:18) [01:26:47:884]: Note: 1: 2318 2: C:\Config.Msi\85833f4f.rbf
MSI (s) (34:18) [01:26:47:900]: Note: 1: 2329 2: 32 3: C:\Program
Files\Company\Product\x86\component2.dll
MSI (s) (34:18) [01:26:47:900]: Verifying accessibility of file:
component2.dll
MSI (s) (34:18) [01:26:47:900]: Note: 1: 2318 2:
MSI (s) (34:18) [01:26:47:900]: Note: 1: 2318 2:
...
Info 1903.Scheduling reboot operation: Deleting file C:\Program
Files\Company\Product\x86\componen2.dll. Must reboot to complete operation.

It is unclear if the original file was still held in use when the new
version was installed.

MSI (s) (34:64) [01:26:56:994]: Executing op:
RegisterSharedComponentProvider(,,File=component2.dll,Component={GUID},ComponentVersion=65535.0.0.0,ProductCode={GUID},ProductVersion=v.v.vvv,PatchSize=0,PatchAttributes=0,PatchSequence=0,SharedComponent=0,IsFullFile=0)
MSI (s) (34:64) [01:26:56:994]: Executing op:
FileCopy(SourceName=component2.dll,SourceCabKey=component2.dll,DestName=component2.dll,Attributes=16384,FileSize=427232,PerTick=65536,,VerifyMedia=1,,,,,CheckCRC=0,Version=65535.0.0.0,Language=1033,InstallMode=58982400,,,,,,,)
MSI (s) (34:64) [01:26:56:994]: File: C:\Program
Files\Company\Product\x86\component2.dll; Overwrite; Won't patch; Existing
file is a lower version
MSI (s) (34:64) [01:26:56:994]: Source for file 'component2.dll' is
compressed
MSI (s) (34:64) [01:26:56:994]: Re-applying security from existing file.
MSI (s) (34:64) [01:26:56:994]: Verifying accessibility of file:
component2.dll
MSI (s) (34:64) [01:26:56:994]: Note: 1: 2318 2:
MSI (s) (34:64) [01:26:56:994]: Note: 1: 2318 2:

-------------------

I still need to identify what had these files held in use *but* it seems
the expected behavior of move/delete on reboot didn't occur successfully
causing problems after reboot.

Has anybody seen this kind of behavior previously? Any ideas on what might
cause the move to fail?

Ideally I would get a ProcMon trace when this happens so that I can have a
better idea of what is actually going on but this doesn't reproduce
consistently so it is hard to have everything capturing and ready to go.
I'm hoping for ideas that might help me generate hypotheses to investigate
and test.

--
Edwin G. Castro

____________________________________________________________________
WiX Toolset Users Mailing List provided by FireGiant http://www.firegiant.com/