This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

AutoUpdate Failure

A few of our endpoint computers are having trouble with the AutoUpdate feature. I have tried to manually update but that fails too. Please advise. Thank you.

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

Time: 5/17/2018 9:39:37
Message: AutoUpdate finished
Module: ALUpdate
Process ID: 3184
Thread ID: 5984

Time: 5/17/2018 9:39:37
Message: Installation of Sophos System Protection skipped
Module: ALUpdate
Process ID: 3184
Thread ID: 5984

Time: 5/17/2018 9:39:37
Message: Installation of Sophos Patch Agent skipped
Module: ALUpdate
Process ID: 3184
Thread ID: 5984

Time: 5/17/2018 9:39:37
Message: Installation of product Sophos AutoUpdate failed
Module: ALUpdate
Process ID: 3184
Thread ID: 5812

Time: 5/17/2018 9:39:19
Message: AutoUpdate finished
Module: SophosUpdate
Process ID: 836
Thread ID: 5172

Time: 5/17/2018 9:39:19
Message: Downloading phase completed
Module: Update
Process ID: 836
Thread ID: 5172

Time: 5/17/2018 9:39:19
Message: ERROR: Download of Endpoint Security and Control failed from server Sophos
Module: Update
Process ID: 836
Thread ID: 5172

Time: 5/17/2018 9:39:19
Message: Could not connect to the server. Check that this computer is connected to the network and that Sophos AutoUpdate is configured to update from the correct location with the correct credentials and proxy details (if required)
Module: Update
Process ID: 836
Thread ID: 5172

Time: 5/17/2018 9:39:19
Message: Downloading product Endpoint Security and Control from server Sophos
Module: Update
Process ID: 836
Thread ID: 5172

Time: 5/17/2018 9:39:18
Message: *************** Sophos AutoUpdate started ***************
Module: SophosUpdate
Process ID: 836
Thread ID: 5172



This thread was automatically locked due to age.
Parents
  • 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.

  • 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(1) and copy it as the xxxxxxxx.msi the Installer is expecting.

    (1) 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.

Reply
  • 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.

Children
  • 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?