Wix Setup not installing when called from Bootstra

Question

I have a Setup.MSI that works perfectly fine.

But when I call it from within a Bootstrapper chain, the installation immediately finishes with a success message without actually installing anything.

It seem like just the step where the MSI should be executed is skipped, as if it has detected an already installed version. It doesn't matter if all previous versions are already uninstalled or the new version is higher. (Altough the execution of the MSI alone always lead to a proper result, where all earlier versions are uninstalled before continuing the installation).

For testing purposes I removed everything but the Setup.msi from my Bootstrapper chain.

The LOG from executing the EXE is:

[0AA8:3E64][2017-03-22T16:41:45]i001: Burn v3.10.3.3007, Windows v10.0 (Build 14393: Service Pack 0), path: C:\Users\bassak\AppData\Local\Temp\{747ED177-C2E5-40F8-8166-FB885ED86990}\.cr\MyProjectFULL.exe
[0AA8:3E64][2017-03-22T16:41:45]i000: Initializing string variable 'InstallFolder' to value '[WindowsVolume]AVL\MyProject'
[0AA8:3E64][2017-03-22T16:41:45]i000: Initializing numeric variable 'CheckBoxInstallSQL' to value '0'
[0AA8:3E64][2017-03-22T16:41:45]i009: Command Line: '"-burn.clean.room=C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\MyProjectFULL.exe" -burn.filehandle.attached=452 -burn.filehandle.self=464 -l log.log'
[0AA8:3E64][2017-03-22T16:41:45]i000: Setting string variable 'WixBundleOriginalSource' to value 'C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\MyProjectFULL.exe'
[0AA8:3E64][2017-03-22T16:41:45]i000: Setting string variable 'WixBundleOriginalSourceFolder' to value 'C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\'
[0AA8:3E64][2017-03-22T16:41:45]i000: Setting string variable 'WixBundleLog' to value 'C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\log.log'
[0AA8:3E64][2017-03-22T16:41:45]i000: Setting string variable 'WixBundleName' to value 'MyProject Bundle'
[0AA8:3E64][2017-03-22T16:41:45]i000: Setting string variable 'WixBundleManufacturer' to value 'AVL List GmbH'
[0AA8:3CE0][2017-03-22T16:41:45]i000: Setting version variable 'WixBundleFileVersion' to value '4.0.1.4'
[0AA8:3E64][2017-03-22T16:41:45]i100: Detect begin, 1 packages
[0AA8:3E64][2017-03-22T16:41:45]i101: Detected package: MyProject.msi, state: Absent, cached: Complete
[0AA8:3E64][2017-03-22T16:41:45]i199: Detect complete, result: 0x0
[0AA8:3CE0][2017-03-22T16:41:46]i000: Setting numeric variable 'CheckBoxInstallSQL' to value 0
[0AA8:3E64][2017-03-22T16:41:46]i200: Plan begin, 1 packages, action: Cache
[0AA8:3E64][2017-03-22T16:41:46]i201: Planned package: MyProject.msi, state: Absent, default requested: Cache, ba requested: Cache, execute: None, rollback: None, cache: No, uncache: No, dependency: None
[0AA8:3E64][2017-03-22T16:41:46]i299: Plan complete, result: 0x0
[0AA8:3E64][2017-03-22T16:41:46]i300: Apply begin
[0AA8:3E64][2017-03-22T16:41:46]i010: Launching elevated engine process.
[0AA8:3E64][2017-03-22T16:41:46]i011: Launched elevated engine process.
[0AA8:3E64][2017-03-22T16:41:46]i012: Connected to elevated engine.
[28E8:47E8][2017-03-22T16:41:46]i358: Pausing automatic updates.
[28E8:47E8][2017-03-22T16:41:46]i359: Paused automatic updates.
[28E8:47E8][2017-03-22T16:41:46]i360: Creating a system restore point.
[28E8:47E8][2017-03-22T16:41:46]i361: Created a system restore point.
[28E8:47E8][2017-03-22T16:41:46]i370: Session begin, registration key: SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall\{9d8bfe4c-e128-400a-a363-4a8b12853b73}, options: 0x7, disable resume: No
[28E8:47E8][2017-03-22T16:41:47]i000: Caching bundle from: 'C:\Users\bassak\AppData\Local\Temp\{1A7728A4-BCE6-4984-8F1C-C94521036C1D}\.be\MyProjectFULL.exe' to: 'C:\ProgramData\Package Cache\{9d8bfe4c-e128-400a-a363-4a8b12853b73}\MyProjectFULL.exe'
[28E8:47E8][2017-03-22T16:41:47]i320: Registering bundle dependency provider: {9d8bfe4c-e128-400a-a363-4a8b12853b73}, version: 4.0.1.4
[28E8:47E8][2017-03-22T16:41:47]i371: Updating session, registration key: SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall\{9d8bfe4c-e128-400a-a363-4a8b12853b73}, resume: Active, restart initiated: No, disable resume: No
[28E8:363C][2017-03-22T16:41:47]i304: Verified existing payload: MyProject.msi at path: C:\ProgramData\Package Cache\{F2ABE5A6-4D93-4F85-B93D-50AD954B2A09}v4.0.1.4\MyProject.msi.
[28E8:47E8][2017-03-22T16:41:47]i372: Session end, registration key: SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall\{9d8bfe4c-e128-400a-a363-4a8b12853b73}, resume: None, restart: None, disable resume: No
[28E8:47E8][2017-03-22T16:41:47]i330: Removed bundle dependency provider: {9d8bfe4c-e128-400a-a363-4a8b12853b73}
[28E8:47E8][2017-03-22T16:41:47]i352: Removing cached bundle: {9d8bfe4c-e128-400a-a363-4a8b12853b73}, from path: C:\ProgramData\Package Cache\{9d8bfe4c-e128-400a-a363-4a8b12853b73}\
[28E8:47E8][2017-03-22T16:41:47]i371: Updating session, registration key: SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall\{9d8bfe4c-e128-400a-a363-4a8b12853b73}, resume: None, restart initiated: No, disable resume: No
[0AA8:3E64][2017-03-22T16:41:48]i399: Apply complete, result: 0x0, restart: None, ba requested restart:  No
[0AA8:3E64][2017-03-22T16:41:49]i500: Shutting down, exit code: 0x0
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: CheckBoxInstallSQL = 0
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: InstallFolder = C:\AVL\MyProject
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WindowsVolume = C:\
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleAction = 4
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleElevated = 1
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleFileVersion = 4.0.1.4
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleInstalled = 0
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleLog = C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\log.log
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleManufacturer = AVL List GmbH
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleName = MyProject Bundle
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleOriginalSource = C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\MyProjectFULL.exe
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleOriginalSourceFolder = C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleProviderKey = {9d8bfe4c-e128-400a-a363-4a8b12853b73}
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleSourceProcessFolder = C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleSourceProcessPath = C:\MyProject Wix\MyProjectSetup\Release\4.0.1.4\MyProjectFULL.exe
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleTag = 
[0AA8:3E64][2017-03-22T16:41:49]i410: Variable: WixBundleVersion = 4.0.1.4
[0AA8:3E64][2017-03-22T16:41:49]i007: Exit code: 0x0, restarting: No

Where could the error be? I have a different Upgrade Code for the setup & the bootstrapper which both always stay the same. As product code I use "*". I use Visual Studio 2015 & build everything at release 32 bit. I am really grateful for every hint into the right direction!

Answer 1

Your problem is related to this line

[0AA8:3E64][2017-03-22T16:41:46]i201: Planned package: MyProject.msi, state: Absent, default requested: Cache, ba requested: Cache, execute: None, rollback: None, cache: No, uncache: No, dependency: None

For some reason the default requested and ba requested are both "Cache". For the installer to run this has to be "Install".

We also have this interesting line

[0AA8:3E64][2017-03-22T16:41:46]i200: Plan begin, 1 packages, action: Cache

I did a bit of digging, and the "Cache" action is a newly added action in 3.10.3. Interestingly, this action was added to the BOOTSTRAPPER_ACTION enum right before BOOTSTRAPPER_ACTION_INSTALL.

So one of two things is happening here, somehow you are building with a binary that is using the old enum so BOOSTRAPPER_ACTION_INSTALL is the same value as the new BOOSTRAPPER_ACTION_CACHE and you are mixing binaries. You build against 3.10.2 or earlier but somehow are shipping with the 3.10.3 dll.

Or, your bootstrapper is setting the action to BOOTSTRAPPER_ACTION_CACHE somewhere.

This should be a good starting point but I can't really figure out exactly what is happening without knowing more.