MSI Understanding the Windows Installer Logs

When people are beginning to use Windows Installer the first look at the logs is often so daunting they tend to never look at them again. I find that the most common reason people avoid the logs is they don’t understand the sequencing. Funnily enough the sequences and the logs tend to correspond with each other (I’m not sure why that is)

Anyway if you take Windows Installer and break it down you would know that the Installer basically consists of a service and a database that processes table’s then sequences and actions. The installer service records everything that happens in sequential logic. The end result is a transactional record of the actions that are run during the installation. The beauty of this is as its transactional its quite simple to apply the reverse logic to handle the uninstall.

Now the trusty old log files record this process in its entirety, basically what I am getting at here is if you take the time to actually read the logs you would also understand the sequencing logic as well because they are one in the same. Alternatively if you work out the sequences you also workout the logs.

So first things first with the logs. How do we enable Windows Installer logging ?

Before we enable logging there is a number of available logging options which you need to know, there are:

Logging Option Option Description
v Verbose output
o Out of disk space messages
i status messages
c Initial UI Parameters
e All error messages
w Non fatal warnings
a start up of actions
r action specific records
m Out of memory or fatal exit information
u user requests
p terminal properties
+ Append to existing file
! Flush each line to the log
x Extra logging (Version 3.0 up, Windows 2003 + OS’s)

Note: Each letter corresponds to a different setting. Adding a collection of all letters increases logging capabilities.

Logging via Registry

System Key: [HKEY_LOCAL_MACHINE\SOFTWARE\Policies\Microsoft\Windows\Installer]
Value Name: Logging
Data Type: REG_SZ (String Value)

MSI_Installer_Logging_HKEY_LOCAL_MACHINE_SOFTWARE_Policies_Microsoft_Windows_Installer


Note: A common acronym of VOICEWARMUP is used as its a word that contains all available settings (prior to V3.0)

Debugging via Registry

System Key: [HKEY_LOCAL_MACHINE\SOFTWARE\Policies\Microsoft\Windows\Installer]
Value Name: Debug
Data Type: REG_DWORD

MSI_Installer_Logging_HKEY_LOCAL_MACHINE_SOFTWARE_Policies_Microsoft_Windows_Installer_Debug


By enabling the debug key you can monitor the installation using debugview

Install script logging

System Key: [HKEY_CURRENT_USER\Software\InstallShield\ISWI\3.0\SetupExeLog]
Value Name: VerboseLogFileName
Data Type: REG_SZ


Windows Installer 4.0 +

So then we got Windows Installer 4.0 from which came two new Windows Installer properties.

MSILogging property hosts the same values listed in the above table.

MSILogFileLocation property has the path to where the logs should be created.

Command Line Logging

So last but not least command line logging, probably the one you will most often use.

msiexec.exe /i /l*v

msiexec.exe /i /l*vx (version 3.0 on Windows 2003 + OS’s)

Reading the logs

Ok so now you have the logs how do we interpret the garbage that it generates. Well for those of you who always like to take the easy road. Get your hands on this little utility WILOGUTL.EXE it makes pretty it all a little more legible and takes the guess work out of things.

However for all of you hard core propeller heads here’s how to really understand the seemingly difficult mess that arrive after setting some of the above options to log.

As you are aware the Installer Service on WindowsNT based platforms offers a client and server based process. The first section depicted in the following log excerpt in blue identifies the process is running client or server side.

MSI (s) (DC:D8) [22:18:04:544]: MainEngineThread is returning 1603
MSI (c) (34:30) [22:18:05:544]: Back from server. Return value: 1603

MSI (S) is server side

MSI (C) is client side

MSI (N) is a nested action

The next items depicted above in the red text is the ProcessID:ThreadID that generated the entry. Only the last 2 (hexadecimal) digits of the process and thread IDs are given. If the process ID was 2DC and thread ID 2D8 the Hex item show in the log would be (DC:D8).

The green section following is the date time stamp the action occurred.

Product State

The ProductState property can be any one of these values

Value Description
-1 The product is neither advertised nor installed.
1 The product is advertised but not installed
2 The product is installed for a different user
5 The product is installed for the current user

Feature Component State

So every feature and component is checked for state prior to it being marked as something that needs to be installed. So selecting different features “usually” changes the feature state and subsequently all the components within that feature (of course there are exceptions to every rule, the condition table and feature / component conditions all have effect here also.).

The first item here, show the feature name as Complete and it is currently Absent. So the requested action is to install it Local. So the components follow the same pattern. This one is a little tricky so more detail here


Value Value: Description
Installed Local        
Source     
Advertise  
Absent
already installed to run local
already installed to run from source
already installed as advertised
not installed
Request Local
Source     
Advertise  
Reinstall   
Absent
requests to install the item to run local
requests to install the item to run from source
requests to advertise the item
requests to reinstall the item
should not be installed
Action Local        
Source     
Reinstall   
Absent     
Null
actually performs install to run local
actually performs install to run from source
actually reinstalls the item
actually removes the item
do nothing

MSI (s) (94:28) [20:46:12:390]: Feature: Complete; Absent: Local;   Request: Local;   Action: Local
MSI (s) (94:28) [20:46:12:390]: Component: Registry; Installed: Absent;   Request: Local;   Action: Local
MSI (s) (94:28) [20:46:12:390]: Component: VersionRegistry; Installed: Local;   Request: Local;   Action: Local
MSI (s) (94:28) [20:46:12:390]: Component: slupExecutable; Installed: Absent;   Request: Local;   Action: Local
MSI (s) (94:28) [20:46:12:390]: Component: CoreLibrary; Installed: Absent;   Request: Local;   Action: Local
MSI (s) (94:28) [20:46:12:390]: Component: CtrlLibrary; Installed: Absent;   Request: Local;   Action: Local

Reading Actions and return codes

Action start 1:18:02: INSTALL.
MSI (c) (A1:6A): UI Sequence table 'InstallUISequence' is
present and populated.
MSI (c) (A1:6A): Running UISequence
MSI (c) (A1:6A): Skipping action: ResumeInstall (condition is false)
MSI (c) (A1:6A): Doing action: CheckOSandSPAction
Action start 1:18:02: CheckOSandSPAction.
MSI (c) (A1:6A): Creating MSIHANDLE (1) of type 790542 for thread 110
Action ended 1:18:02: CheckOSandSPAction. Return value 1.
The valid return codes are:
Value Description
0

Action not invoked; most likely does not exist.

1

Completed actions successfully.

2

User terminated prematurely.

3

Unrecoverable error occurred.

4

Sequence suspended, to be resumed later.

Shell32 API calls

Where you see one of these there is a good chance a directory is being resolved for the current target platform.

MSI (s) (94:28) [20:46:11:843]: SHELL32::SHGetFolderPath returned: C:\Documents and Settings\All Users\Templates

Old hands tips for log reading

1) Start at the bottom and work up

2) If your install fails with dialogs open. Leave dialogs on screen and goto log whilst error message is still visible

3) Use WiLogUtl.exe

4) Don’t forget the newest extended logging options /l*vx (most of you are still using /l*v)

5) Keep the sequences in mind when reading a logfile (strangely enough they coincide nicely)

6) Enable GPO logging or policy registry option if you need to log repairs

7) Now you have this information take a 30 minutes out of your day and read an entire log you’ll be surprised what you learn.

Now all that being said, I’m not getting a lot of feedback about these blogs so its hard to gauge if anyone is really reading or even interested in this stuff or not.

5 thoughts on “MSI Understanding the Windows Installer Logs

  1. Thanks for this information. In the middle of trying to determine why an appsearch is failing saying it has already run client side when the log doesnt show it.

  2. Thanks a lot for this information. Never seen a such complete and precise msi log description. Very useful. Good job !

  3. Great inforamation….

    Sleeping today with a satisfaction that i learnt something new today… 🙂

  4. Very useful and insightful. Thanks. I hope I’m now a step closer to solving my problem.

Leave a Reply

Your email address will not be published. Required fields are marked *