AutoUpdate Failure

Hello Noah Doten,

the more verbose ALUpdate log (in %ProgramData%\Sophos\AutoUpdate\Logs\) should have more details why it fails to download from Sophos. Are these stand-alone installations?

Christian

ALUpdate20180516T181749.9161900.log

Thanks for the reply. Attached the log for you. It is a server-based install.

ALUpdate20180516T181749.9161900.log

Thanks for the reply. Attached the log for you. It is a server-based install.

Hello Noah Doten,

strange - and I must admit I have overlooked the AutoUpdate install error..
Strange because the ALUpdate has a gap and jumps from 09:39:03 to 09:39:37 which is expected as it attempts to install an update. The updating log in your original post shows a download error during this gap and furthermore that it failed to download from Sophos - whereas the ALUpdate log shows only successful UNC connections.

Time: 5/17/2018 9:39:19
Message: AutoUpdate finished
...
Time: 5/17/2018 9:39:37
Message: AutoUpdate finished
The above looks as if two logs were merged or two AutoUpdate processes were running in parallel - note the process IDs. There's no indication of the download error in the ALUpdate log you've shown.

As for the AutoUpdate install error: You should find the log in %windir%\Temp\.

Christian

Christian,

Is this what you were looking for? Thanks.

17-05-2018 09:39:03 Successfully requested Sophos Endpoint Defense disable tamper protection of SAU.
17-05-2018 09:39:03 In MsiLib::GetPackageProductInfo().
17-05-2018 09:39:03 In MsiLib::GetPackageProperty().
17-05-2018 09:39:03 Leaving MsiLib::GetPackageProperty() with ERROR_SUCCESS.
17-05-2018 09:39:03 In MsiLib::GetPackageProperty().
17-05-2018 09:39:03 Leaving MsiLib::GetPackageProperty() with ERROR_SUCCESS.
17-05-2018 09:39:03 In MsiLib::GetPackageProperty().
17-05-2018 09:39:03 Leaving MsiLib::GetPackageProperty() with ERROR_SUCCESS.
17-05-2018 09:39:03 Leaving MsiLib::GetPackageProductInfo().
17-05-2018 09:39:03 In MsiLib::IsProductInstalled().
17-05-2018 09:39:03 Leaving MsiLib::IsProductInstalled() with true.
17-05-2018 09:39:03 In FixIniFiles().
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\iconn.cfg
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\idata.cfg
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\ilog.cfg
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\imon.cfg
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\isched.cfg
17-05-2018 09:39:03 Processing: C:\ProgramData\Sophos\AutoUpdate\Config\iupd.cfg
17-05-2018 09:39:03 Installation type: Major upgrade/sidegrade.
17-05-2018 09:39:03 Disabling custom actions in cached Sophos AutoUpdate MSI.
17-05-2018 09:39:03 About to disable custom actions in cached MSI.
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 MsiDatabaseOpenView failed with error: 6
17-05-2018 09:39:03 Failed to disable custom actions from cached MSI.  Error: 6.
17-05-2018 09:39:03 Creating a registry saver.
17-05-2018 09:39:03 Uninstall current product.
17-05-2018 09:39:03 MSI installation attempt: 1
17-05-2018 09:39:05 Installation of Sophos AutoUpdate failed with return code : 1603.
17-05-2018 09:39:10 MSI installation attempt: 2
17-05-2018 09:39:12 Installation of Sophos AutoUpdate failed with return code : 1603.
17-05-2018 09:39:17 MSI installation attempt: 3
17-05-2018 09:39:19 Installation of Sophos AutoUpdate failed with return code : 1603.
17-05-2018 09:39:24 MSI installation attempt: 4
17-05-2018 09:39:25 Installation of Sophos AutoUpdate failed with return code : 1603.
17-05-2018 09:39:30 MSI installation attempt: 5
17-05-2018 09:39:32 Installation of Sophos AutoUpdate failed with return code : 1603.
17-05-2018 09:39:37 Failed to successfully install MSI within 5 attempts
17-05-2018 09:39:37 Successfully registered for tamper protection with Sophos Endpoint Defense.
17-05-2018 09:39:37 Error: Install of MSI failed with error 1603

Hello Noah Doten,

seems to be the Sophos AutoUpdate 5.nn.nnn setup log, is there also a Sophos AutoUpdate 5.nn.nnn install log?
Error 6 is The handle is invalid, a possible reason is the the cached MSI required for uninstallation of the current version is missing. In the install log (if it is there) there should be a line like
Original package ==> C:\Windows\Installer\xxxxxxxx.msi
where xxxxxxxx are hex digits. This is a cached copy of the AutoUpdate.msi from the currently installed version. If it's indeed missing you'll find a corresponding message in one of the following lines. You'd need the relevant AutoUpdate.msi⁽¹⁾ and copy it as the xxxxxxxx.msi the Installer is expecting.

⁽¹⁾ if you don't have the older MSI lying about somewhere you need to add a subscription in your SUM for the appropriate version.

Christian

Hey Christian, Sorry for the late response. Does this confirm your suspicion? Thanks again for your help.

MSI (s) (B4:F4) [09:39:05:455]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:455]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: Warning: Local cached package 'C:\Windows\Installer\14f0488.msi' is missing.
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: User policy value 'SearchOrder' is 'nmu'
MSI (s) (B4:F4) [09:39:05:456]: User policy value 'DisableMedia' is 0
MSI (s) (B4:F4) [09:39:05:456]: Machine policy value 'AllowLockdownMedia' is 0
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Media enabled only if package is safe.
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Looking for sourcelist for product {7CD26A0C-9B59-4E84-B5EE-B386B2F7AA16}
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Adding {7CD26A0C-9B59-4E84-B5EE-B386B2F7AA16}; to potential sourcelist list (pcode;disk;relpath).
MSI (s) (B4:F4) [09:39:05:456]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Now checking product {7CD26A0C-9B59-4E84-B5EE-B386B2F7AA16}
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Media is enabled for product.
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Attempting to use LastUsedSource from source list.
MSI (s) (B4:F4) [09:39:05:456]: SOURCEMGMT: Trying source C:\ProgramData\Sophos\AutoUpdate\cache\sau\.
MSI (s) (B4:F4) [09:39:05:457]: Using cached product context: machine assigned for product: C0A62DC795B948E45BEE3B682B7FAA61
MSI (s) (B4:F4) [09:39:05:457]: Creating MSIHANDLE (154) of type 790541 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: Creating MSIHANDLE (155) of type 790540 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: Creating MSIHANDLE (156) of type 790531 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: Closing MSIHANDLE (156) of type 790531 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: Closing MSIHANDLE (155) of type 790540 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: Closing MSIHANDLE (154) of type 790541 for thread 4340
MSI (s) (B4:F4) [09:39:05:459]: SOURCEMGMT: Source is invalid due to invalid package code (product code doesn't match).
MSI (s) (B4:F4) [09:39:05:459]: Note: 1: 1706 2: -2147483646 3: Sophos AutoUpdate.msi
MSI (s) (B4:F4) [09:39:05:459]: SOURCEMGMT: Processing net source list.
MSI (s) (B4:F4) [09:39:05:459]: Note: 1: 1706 2: -2147483647 3: Sophos AutoUpdate.msi
MSI (s) (B4:F4) [09:39:05:459]: SOURCEMGMT: Processing media source list.
MSI (s) (B4:F4) [09:39:05:470]: Note: 1: 2203 2: 3: -2147287037
MSI (s) (B4:F4) [09:39:05:470]: SOURCEMGMT: Source is invalid due to missing/inaccessible package.
MSI (s) (B4:F4) [09:39:05:470]: Note: 1: 1706 2: -2147483647 3: Sophos AutoUpdate.msi
MSI (s) (B4:F4) [09:39:05:470]: SOURCEMGMT: Processing URL source list.
MSI (s) (B4:F4) [09:39:05:470]: Note: 1: 1402 2: UNKNOWN\URL 3: 2
MSI (s) (B4:F4) [09:39:05:470]: Note: 1: 1706 2: -2147483647 3: Sophos AutoUpdate.msi
MSI (s) (B4:F4) [09:39:05:470]: Note: 1: 1706 2: 3: Sophos AutoUpdate.msi
MSI (s) (B4:F4) [09:39:05:471]: SOURCEMGMT: Failed to resolve source
MSI (s) (B4:2C) [09:39:05:472]: Note: 1: 1714 2: Sophos AutoUpdate 3: 1612
CustomAction returned actual error code 1612 (note this may not be 100% accurate if translation happened inside sandbox)
MSI (s) (B4:2C) [09:39:05:472]: Product: Sophos AutoUpdate -- Error 1714.The older version of Sophos AutoUpdate cannot be removed. Contact your technical support group. System Error 1612.

Error 1714.The older version of Sophos AutoUpdate cannot be removed. Contact your technical support group. System Error 1612.
MSI (s) (B4:2C) [09:39:05:475]: User policy value 'DisableRollback' is 0
MSI (s) (B4:2C) [09:39:05:475]: Machine policy value 'DisableRollback' is 0
MSI (s) (B4:2C) [09:39:05:475]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2
Action ended 9:39:05: RemoveExistingProducts. Return value 3.
MSI (s) (B4:2C) [09:39:05:475]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2
MSI (s) (B4:2C) [09:39:05:475]: No System Restore sequence number for this installation.
MSI (s) (B4:2C) [09:39:05:476]: Unlocking Server
Action ended 9:39:05: INSTALL. Return value 3.

Hello Noah Doten,

as expected:

Warning: Local cached package 'C:\Windows\Installer\14f0488.msi' is missing

it looks for the previous AutoUpdate.msi, usually the Installer caches a package to facilitate uninstall in case it has been removed from or overwritten in the original location. Can't say why it has apparently disappeared. As you can see the Installer then tries the original location, the package there is the new one though so the uninstall fails.

As said, you can solve it by supplying the appropriate package - or should I say could? AFAIK Productcode {7CD26A0C-9B59-4E84-B5EE-B386B2F7AA16} indicates an AutoUpdate 4.x version, part of SESC 10.6.x which is no longer available. thus the endpoints must have shown these errors for quite some time.

Christian 

So there is no way I can install the missing msi?