Every time that the Deployment Tool runs a Microsoft Windows Installer (MSI) either to install or uninstall a component, it always generates a log file and stores it in the ConfigShare\Log directory. The file name is in the following format:

<MSIName> on <ServerName> <Date>_<Time>.log

The log file is generated by using the MSIExec command-line switch /l*v! which approximately translates everything to log. This results in very long log files that are difficult to read. This section describes how to read Deployment Tool generated MSI logs.

  1. Start by scrolling to the very bottom to find a summary of the MSI running log. The summary can help you determine what you are looking at, as shown in the following example:
      Copy Code 
    ... 
=== Logging stopped: 2/24/2006  12:44:33 === 
MSI (s) (74:A8) [12:44:33:444]: Note: 1: 1708 
MSI (s) (74:A8) [12:44:33:484]: Product: Microsoft Provisioning Framework Enterprise Edition -- Installation operation failed.
  
MSI (s) (74:A8) [12:44:33:825]: Cleaning up uninstalled install packages, if any exist
MSI (s) (74:A8) [12:44:33:875]: MainEngineThread is returning 1603
MSI (s) (74:D8) [12:44:33:935]: Destroying RemoteAPI object. 
MSI (s) (74:AC) [12:44:33:965]: Custom Action Manager thread ending. 
MSI &copy;) (1C:B8) [12:44:34:025]: Decrementing counter to disable shutdown. If counter &gt;= 0, shutdown will be denied.  Counter after decrement: -1 
MSI &copy;) (1C:B8) [12:44:34:065]: MainEngineThread is returning 1603 
=== Verbose logging stopped: 2/24/2006  12:44:34 ===
    All this really tells that the installation of the Microsoft Provisioning Framework Enterprise Edition failed. To determine more, we must find the actual point of failure in the log.
  2. Directly above this summary is a long list of Property(S). These are rarely helpful in determining what is wrong, so we have to look to the lines directly above this list of Property(S). In the sample below, we can see that the installation Action ended with a Return value 3.
      Copy Code 
    ...
Action ended 12:44:21: INSTALL. Return value 3. 
Property(S): ProductName = Microsoft Provisioning Framework Enterprise Edition 
Property(S): ProductVersion = 13.3.0609.0005 
Property(S): Manufacturer = Microsoft Corporation 
... 
Property(S): MPF_CONTOLRAPI_ACCESS_ACL = D:(A;;0x0100;;;S-1-5-21-1862170175-426256359-1674568132-1119) 
... 
=== Logging stopped: 2/24/2006  12:44:33 ===
  3. This Return value is important and will be used later. The lines directly above the return value are related to a rollback operation (the failed installation is being rolled back), as shown in the following sample:
      Copy Code 
    MSI (s) (74:A8) [12:44:18:703]: Executing op: FolderRemove(Folder=C:\Program Files\Microsoft Provisioning\Tools\Admin\,Foreign=0) 
MSI (s) (74:A8) [12:44:18:753]: Executing op: FolderRemove(Folder=C:\Program Files\Microsoft Provisioning\Core\,Foreign=0) 
... 
MSI (s) (74:A8) [12:44:19:354]: Executing op: RegRemoveValue(Name=C:\WINDOWS\system32\msvcp60.dll,Value=#+,) 
... 
MSI (s) (74:A8) [12:44:21:367]: Executing op: ComponentUnregister(ComponentId={C0CB73DE-ACE6-4A6F-97E0-A514BFE0A199},ProductKey={450F69CF-9A86-494E-949A-B5C18DE5D46D},BinaryType=0,) 
MSI (s) (74:A8) [12:44:21:407]: Executing op: End(Checksum=0,ProgressTotalHDWord=0,ProgressTotalLDWord=0) 
MSI (s) (74:A8) [12:44:21:447]: Error in rollback skipped.		Return: 5 
MSI (s) (74:A8) [12:44:21:507]: No System Restore sequence number for this installation. 
MSI (s) (74:A8) [12:44:21:547]: Unlocking Server 
MSI (s) (74:A8) [12:44:21:588]: PROPERTY CHANGE: Deleting UpdateStarted property. Its current value is '1'. 
Action ended 12:44:21: INSTALL. Return value 3.
  4. Search up the log for any other instances of the string "Return value 3". Almost 500 lines above the "Action ended..." line, we find the following:
      Copy Code 
    Action start 12:43:41: MapsRunSQLScripts. 
MSI (s) (74:9C) [12:43:41:751]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI7ED.tmp, Entrypoint: MapsRunSQLScripts 
Entering CustomAction MapsRunSQLScripts 
((INFO)) RunSQLScript: Precondition: (&amp;MapsTranLogFeature=2) AND (MPF_IS_VALID_CONFIGDB&lt;&gt;"0") failed (SQL script #1). Skip to next SQL script. 
((INFO)) RunSQLScript: Precondition: (&amp;MapsAuditFeature=2) AND (MPF_IS_VALID_CONFIGDB&lt;&gt;"0") failed (SQL script #2). Skip to next SQL script. 
((INFO)) RunSQLScript: Precondition:  (&amp;MapsConfigFeature=3) AND (&amp;MapsConfigDirsFeature=3) failed (SQL script #100). Skip to next SQL script. 
((INFO)) RunSQLScript: Running SQL script #101 
((INFO)) RunSQLScript: Precondition:  (&amp;MapsConfigFeature=3) AND (UPGRADE=2) failed (SQL script #102). Skip to next SQL script. 
((INFO)) RunSQLScript: Running SQL script #103 
((INFO)) RunSQLScript: Running SQL script #104 
((INFO)) RunSQLScript: Running SQL script #106 
((INFO)) RunSQLScript: Precondition:  (&amp;MapsTranLogFeature=3) AND (&amp;MapsTranLogDirsFeature=3) failed (SQL script #110). Skip to next SQL script. 
((INFO)) RunSQLScript: Running SQL script #111 
((INFO)) RunSQLScript: Precondition: (&amp;MapsTranLogFeature=3) AND (UPGRADE=2) failed (SQL script #112). Skip to next SQL script. 
((INFO)) RunSQLScript: Running SQL script #113 
((INFO)) DumpErrorInfo: HRESULT: 80040e14 
((INFO)) DumpErrorInfo: SQLSTATE: 42000 Native Error: 215 
((INFO)) DumpErrorInfo: Error state: 1 Severity: 16 
((INFO)) DumpErrorInfo: Source: Microsoft OLE DB Provider for SQL Server 
((INFO)) DumpErrorInfo: Error message: Parameters supplied for object 'BM_ParentBatches' which is not a function. If the parameters are intended as a table hint, a WITH keyword is required. 
((INFO)) DumpErrorInfo: HRESULT: 80040e14 
((INFO)) DumpErrorInfo: SQLSTATE: 42S22 Native Error: 207 
((INFO)) DumpErrorInfo: Error state: 1 Severity: 16 
((INFO)) DumpErrorInfo: Source: Microsoft OLE DB Provider for SQL Server 
((INFO)) DumpErrorInfo: Error message: Invalid column name 'updlock'. 
((INFO)) DumpErrorInfo: HRESULT: 80040e14 
((INFO)) DumpErrorInfo: SQLSTATE: 42S22 Native Error: 207 
((INFO)) DumpErrorInfo: Error state: 1 Severity: 16 
((INFO)) DumpErrorInfo: Source: Microsoft OLE DB Provider for SQL Server 
((INFO)) DumpErrorInfo: Error message: Invalid column name 'rowlock'. 
((ERROR)) ExecTSQLCommand: There was an error executing the command, hr=0x80040e14 
MSI (s) (74!44) [12:44:01:028]: Product: Microsoft Provisioning Framework Enterprise Edition -- ((ERROR)) ExecTSQLCommand: There was an error executing the command, hr=0x80040e14 
 
((INFO)) GetAdditionalErrorInfo: No additional error information 
((ERROR)) FixApplySQLScript: Error executing SQL command, hr=0x80040e14 
MSI (s) (74!44) [12:44:01:148]: Product: Microsoft Provisioning Framework Enterprise Edition -- ((ERROR)) FixApplySQLScript: Error executing SQL command, hr=0x80040e14 
 
((ERROR)) RunSQLScript: ApplySQLScript #113 failed., hr=0x80040e14 
MSI (s) (74!44) [12:44:01:419]: Product: Microsoft Provisioning Framework Enterprise Edition -- ((ERROR)) RunSQLScript: ApplySQLScript #113 failed., hr=0x80040e14 
 
((INFO)) GetAdditionalErrorInfo: No additional error information 
((ERROR)) MapsRunSQLScripts: MapsRunSQLScripts failed., hr=0x80040e14 
MSI (s) (74!44) [12:44:01:509]: Product: Microsoft Provisioning Framework Enterprise Edition -- ((ERROR)) MapsRunSQLScripts: MapsRunSQLScripts failed., hr=0x80040e14 
 
((ERROR)) MapsRunSQLScripts: FAILED, hr=0x80040e14 
MSI (s) (74!44) [12:44:01:599]: Product: Microsoft Provisioning Framework Enterprise Edition -- ((ERROR)) MapsRunSQLScripts: FAILED, hr=0x80040e14 
 
Action ended 12:44:01: MapsRunSQLScripts. Return value 3.
    Here we will find the real source of the problem which in this case was related to trying to install the MPF Databases on to a server running SQL 2005. This will fail for any build of MPF earlier than version 2.2. This is indicated by the syntax errors running the SQL Scripts.
  5. Another line in the MSI log that is sometimes of value is the Command Line. In the previous example, the lines that the command line passed to MSIExec looked as follows:
      Copy Code 
    MSI (s) (74:A8) [12:41:59:184]: Command Line: UNATTENDED=1 MPF_IMPERSONATE=1 MPFRMLOG=1 LISTENER_IS_DEPENDENT_ON_SQL=no RM_SERVER=SQL01-RAD 
 MPF_AUDIT_SERVER=SQL01-RAD MPFAUDIT=1 MPFCONFIG=1 MPFSVCPASSWORD=********** MPF_TRANLOG_SERVER=SQL01-RAD MPF_CONFIG_SERVER=SQL01-RAD 
 DEPLOY_PDB=0 MPF_DOMAIN_INSTALL=1 MPFTRANLOG=1 MPF_LISTENER_SERVER=SQL01-RAD MPFADMIN=1 BATCH_IS_DEPENDENT_ON_SQL=no 
 CURRENTDIRECTORY=C:\WINDOWS\system32 CLIENTUILEVEL=3 CLIENTPROCESSID=3868