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

Update from HTTP CID failing after updating to SAV 10.7.6 and SAU 5.10.139

Update from HTTP CID failing after updating to SAV 10.7.6 and SAU 5.10.139

Reinstalling the earlier version works fine.

Do I need to make a change to IIS?

 

I have a case logged with Sophos, just checking if anyone else has the same issue?



This thread was automatically locked due to age.
  • Hello Ahsan Amin,

    I'm not aware of any changes in the CID that cause problems or that SAU 5.10 fails on an IIS CID.
    [shamelessly quoting a post I've writte just a few minutes ago]
    please check the ALUpdate log on the endpoints one should suffice as the error seems to be the same for all - BTW: Does your SEC server update or does it show the same error? Please note: If you follow the ALUpdate.log link in the article it takes you to the significant files article but the location given there is incorrect, the ALUpdate.log is in %ProgramData%\Sophos\AutoUpdate\Logs\. If you want us to have a look at it even though you've logged a case please post one complete cycle here. 

    Christian

  • Trace(2018-Jan-29 15:56:24): =========================
    Trace(2018-Jan-29 15:56:24): ALUpdate is starting.
    Trace(2018-Jan-29 15:56:24): AutoUpdate version: 5.10
    Trace(2018-Jan-29 15:56:24): Build : 210356
    Trace(2018-Jan-29 15:56:24): Command line : -ScheduledUpdate -NoGUI -RootPath "C:\Program Files (x86)\Sophos\AutoUpdate"
    Trace(2018-Jan-29 15:56:24): =========================
    Trace(2018-Jan-29 15:56:24): Process security set successfully
    Trace(2018-Jan-29 15:56:24): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} has been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} is available from Sophos.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} is not the Spam Rules package.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} has not been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} has been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is available from Sophos.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is not the Spam Rules package.
    Trace(2018-Jan-29 15:56:24): Product subscription is disabled: iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} action value is:0
    Trace(2018-Jan-29 15:56:24): Product iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} has not been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{3B758ED7-87C1-4e89-BDE1-F49DFF1249F6} has not been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} has been added.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is available from Sophos.
    Trace(2018-Jan-29 15:56:24): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is the Spam Rules package.
    Trace(2018-Jan-29 15:56:24): Computer is a not possible cluster
    Trace(2018-Jan-29 15:56:24): PureMessageDetector::AreSpamRulesRequired - Could not open registry on Software\Sophos\MMEx\Config\Global
    Trace(2018-Jan-29 15:56:24): ConfigurationImpl, considering PMSR 2.6: PureMessage not installed, PMSR package will not be updated without a subscription
    Trace(2018-Jan-29 15:56:24): Considering subscribed products.
    Trace(2018-Jan-29 15:56:24): Considering product {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-29 15:56:24): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is not already subscribed.
    Trace(2018-Jan-29 15:56:24): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} was added to the list.
    Trace(2018-Jan-29 15:56:24): Considering product {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-29 15:56:24): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is not already subscribed.
    Trace(2018-Jan-29 15:56:24): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} was added to the list.
    Trace(2018-Jan-29 15:56:24): Considering product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
    Trace(2018-Jan-29 15:56:24): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} is not already subscribed.
    Trace(2018-Jan-29 15:56:24): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} was added to the list.
    Trace(2018-Jan-29 15:56:24): Considering product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-29 15:56:24): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is not already subscribed.
    Trace(2018-Jan-29 15:56:24): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} was added to the list.
    Trace(2018-Jan-29 15:56:24): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is removable.
    Trace(2018-Jan-29 15:56:24): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is removable.
    Trace(2018-Jan-29 15:56:24): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is removable.
    Trace(2018-Jan-29 15:56:24): IPCBase::IPCBase: Connected to shared memory A32951C539924a12B3C8F2FDA5A268E4
    Trace(2018-Jan-29 15:56:24): IPCSender::ProcessSend started
    Trace(2018-Jan-29 15:56:24): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-29 15:56:24): RMSMessageHandler: ALUpdateStart
    Trace(2018-Jan-29 15:56:24): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-29 15:56:24): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-29 15:56:24): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-29 15:56:24): ALUpdate(AutoUpdate.Started):
    Trace(2018-Jan-29 15:56:24): UpdateCoordinator::UpdateNow: Entering
    Trace(2018-Jan-29 15:56:24): PopulateCache: Entering
    Trace(2018-Jan-29 15:56:24): UpdateCoordinator::UpdateNow: current platform is WIN_7_X64
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SimpleProduct: {390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92}
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SimpleProduct: {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SimpleProduct: {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SimpleProduct: {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SAU Product
    Trace(2018-Jan-29 15:56:24): ProductFactory::Create: SimpleProduct: {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-29 15:56:24): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Entering
    Trace(2018-Jan-29 15:56:24): Processing CID update location: http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:24): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Finished. Number of new locations added: 0
    Trace(2018-Jan-29 15:56:24): UpdateCoordinator::UpdateNow: About to Sync list of products
    Trace(2018-Jan-29 15:56:24): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-29 15:56:24): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-29 15:56:24): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-29 15:56:24): Calling package_source_init
    Trace(2018-Jan-29 15:56:24): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-29 15:56:24): Custom certificate already present.
    Trace(2018-Jan-29 15:56:24): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-29 15:56:24): Remote connection over HTTP.
    Trace(2018-Jan-29 15:56:24): File master.upd not found (Remote). Return code 0x80040f04
    Trace(2018-Jan-29 15:56:24): Unable to read file master.upd (Remote)
    Trace(2018-Jan-29 15:56:24): Unable to synchronise file root.upd.
    Trace(2018-Jan-29 15:56:24): Unable to synchronise file escdp.dat.
    Trace(2018-Jan-29 15:56:24): Unable to synchronise file expired_credential.dat.
    Trace(2018-Jan-29 15:56:24): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-29 15:56:24): Unable to synchronise file ProductID.dat.
    Trace(2018-Jan-29 15:56:24): File root.upd recovered.
    Trace(2018-Jan-29 15:56:24): File escdp.dat recovered.
    Trace(2018-Jan-29 15:56:24): File ProductID.dat recovered.
    Trace(2018-Jan-29 15:56:24): Unable to recover file expired_credential.dat.
    Trace(2018-Jan-29 15:56:24): Error -2147217660 in ReadCustomerIDFile
    Trace(2018-Jan-29 15:56:24): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92}
    Trace(2018-Jan-29 15:56:24): CIDUpdateLocation::SyncProduct - Updating Product: RMSNT
    Trace(2018-Jan-29 15:56:24): CIDUpdate(SyncProduct.Start): RMSNT, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:24): CIDUpdateLocation::Sync - Updating from http CID: http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/rms
    Trace(2018-Jan-29 15:56:24): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:24): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:24): CIDSyncCallback, SynchronisationTerminated - Code = -2147217660
    Trace(2018-Jan-29 15:56:24): CIDSyncCallback, SynchronisationTerminated - MapFile = C:\ProgramData\Sophos\AutoUpdate\cache\rms.map
    Trace(2018-Jan-29 15:56:24): CIDUpdateLocation::SyncProduct: Failed to update product (RMSNT) from "http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/", Error is :CIDSYNC_E_FILESYNCERROR (Error during file download.)
    Trace(2018-Jan-29 15:56:24): CIDUpdate(CIDDownloadFailed): RMSNT, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:25): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 0
    Trace(2018-Jan-29 15:56:25): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 0
    Trace(2018-Jan-29 15:56:25): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-29 15:56:25): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-29 15:56:25): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-29 15:56:25): Calling package_source_init
    Trace(2018-Jan-29 15:56:25): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-29 15:56:25): Custom certificate already present.
    Trace(2018-Jan-29 15:56:25): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-29 15:56:25): Remote connection over HTTP.
    Trace(2018-Jan-29 15:56:25): File master.upd not found (Remote). Return code 0x80040f04
    Trace(2018-Jan-29 15:56:25): Unable to read file master.upd (Remote)
    Trace(2018-Jan-29 15:56:25): Unable to synchronise file root.upd.
    Trace(2018-Jan-29 15:56:25): Unable to synchronise file escdp.dat.
    Trace(2018-Jan-29 15:56:25): Unable to synchronise file expired_credential.dat.
    Trace(2018-Jan-29 15:56:25): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-29 15:56:25): Unable to synchronise file ProductID.dat.
    Trace(2018-Jan-29 15:56:25): File root.upd recovered.
    Trace(2018-Jan-29 15:56:25): File escdp.dat recovered.
    Trace(2018-Jan-29 15:56:25): File ProductID.dat recovered.
    Trace(2018-Jan-29 15:56:25): Unable to recover file expired_credential.dat.
    Trace(2018-Jan-29 15:56:25): Error -2147217660 in ReadCustomerIDFile
    Trace(2018-Jan-29 15:56:25): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-29 15:56:25): CIDUpdateLocation::SyncProduct - Updating Product: SAVXP
    Trace(2018-Jan-29 15:56:25): CIDUpdate(SyncProduct.Start): SAVXP, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:25): CIDUpdateLocation::Sync - Updating from http CID: http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/savxp
    Trace(2018-Jan-29 15:56:25): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:25): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:25): CIDSyncCallback, SynchronisationTerminated - Code = -2147217660
    Trace(2018-Jan-29 15:56:25): CIDSyncCallback, SynchronisationTerminated - MapFile = C:\ProgramData\Sophos\AutoUpdate\cache\savxp.map
    Trace(2018-Jan-29 15:56:25): CIDUpdateLocation::SyncProduct: Failed to update product (SAVXP) from "http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/", Error is :CIDSYNC_E_FILESYNCERROR (Error during file download.)
    Trace(2018-Jan-29 15:56:25): CIDUpdate(CIDDownloadFailed): SAVXP, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:26): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 0
    Trace(2018-Jan-29 15:56:26): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 0
    Trace(2018-Jan-29 15:56:26): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-29 15:56:26): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-29 15:56:26): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-29 15:56:26): Calling package_source_init
    Trace(2018-Jan-29 15:56:26): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-29 15:56:26): Custom certificate already present.
    Trace(2018-Jan-29 15:56:26): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-29 15:56:26): Remote connection over HTTP.
    Trace(2018-Jan-29 15:56:26): File master.upd not found (Remote). Return code 0x80040f04
    Trace(2018-Jan-29 15:56:26): Unable to read file master.upd (Remote)
    Trace(2018-Jan-29 15:56:26): Unable to synchronise file root.upd.
    Trace(2018-Jan-29 15:56:26): Unable to synchronise file escdp.dat.
    Trace(2018-Jan-29 15:56:26): Unable to synchronise file expired_credential.dat.
    Trace(2018-Jan-29 15:56:26): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-29 15:56:26): Unable to synchronise file ProductID.dat.
    Trace(2018-Jan-29 15:56:26): File root.upd recovered.
    Trace(2018-Jan-29 15:56:26): File escdp.dat recovered.
    Trace(2018-Jan-29 15:56:26): File ProductID.dat recovered.
    Trace(2018-Jan-29 15:56:26): Unable to recover file expired_credential.dat.
    Trace(2018-Jan-29 15:56:26): Error -2147217660 in ReadCustomerIDFile
    Trace(2018-Jan-29 15:56:26): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-29 15:56:26): CIDUpdateLocation::SyncProduct - Updating Product: Sophos Endpoint Defense
    Trace(2018-Jan-29 15:56:26): CIDUpdate(SyncProduct.Start): Sophos Endpoint Defense, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:26): CIDUpdateLocation::Sync - Updating from http CID: http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/sed64
    Trace(2018-Jan-29 15:56:26): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:26): CIDSync(CidSyncMessage):
    Trace(2018-Jan-29 15:56:26): CIDSyncCallback, SynchronisationTerminated - Code = -2147217660
    Trace(2018-Jan-29 15:56:26): CIDSyncCallback, SynchronisationTerminated - MapFile = C:\ProgramData\Sophos\AutoUpdate\cache\sed64.map
    Trace(2018-Jan-29 15:56:26): CIDUpdateLocation::SyncProduct: Failed to update product (Sophos Endpoint Defense) from "http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/", Error is :CIDSYNC_E_FILESYNCERROR (Error during file download.)
    Trace(2018-Jan-29 15:56:26): CIDUpdate(CIDDownloadFailed): Sophos Endpoint Defense, http://avupdate.XXXX.XX/sophos/winhome/CIDs/S063/SAVSCFXP/
    Trace(2018-Jan-29 15:56:27): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 0
    Trace(2018-Jan-29 15:56:27): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 0
    Trace(2018-Jan-29 15:56:27): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-29 15:56:27): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-29 15:56:27): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-29 15:56:27): Calling package_source_init
    Trace(2018-Jan-29 15:56:27): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-29 15:56:27): Custom certificate already present.
    Trace(2018-Jan-29 15:56:27): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-29 15:56:27): Remote connection over HTTP.
    Trace(2018-Jan-29 15:56:27): File master.upd not found (Remote). Return code 0x80040f04
    Trace(2018-Jan-29 15:56:27): Unable to read file master.upd (Remote)
    Trace(2018-Jan-29 15:56:27): Unable to synchronise file root.upd.
    Trace(2018-Jan-29 15:56:27): Unable to synchronise file escdp.dat.
    Trace(2018-Jan-29 15:56:27): Unable to synchronise file expired_credential.dat.
    Trace(2018-Jan-29 15:56:27): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-29 15:56:27): Unable to synchronise file ProductID.dat.
    Trace(2018-Jan-29 15:56:27): File root.upd recovered.
    Trace(2018-Jan-29 15:56:27): File escdp.dat recovered.
    Trace(2018-Jan-29 15:56:27): File ProductID.dat recovered.
    Trace(2018-Jan-29 15:56:27): Unable to recover file expired_credential.dat.
    Trace(2018-Jan-29 15:56:27): Error -2147217660 in ReadCustomerIDFile
    Trace(2018-Jan-29 15:56:27): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ca

  • QC said:

    BTW: Does your SEC server update or does it show the same error?

    The person who setup Sophos no longer works here and the backup is off sick. I've been figuring out how it all fits together by following the guides and posts here.

    I deleted the SAVSCFXP folder from the "Initial Install Source" and watched as the SUM recreated it.

    Any clients on SAU 5.7.533 are able to connect to the HTTP CID, download and update to SAU 5.10.139. Once on the new SAU version, they are unable to connect to the server. This included the SEC which also updated to 5.10.139.

  • Hello Ahsan Amin,

    you say Reinstalling the earlier version works fine - the earlier version is on a different (not S063) CID? Do you have a log from a successful update of this version?
    And could you try to open .../sophos/winhome/CIDs/S063/SAVSCFXP/master.upd with a browser?

    Christian

  • All the failing clients are able to browse to http://.../SAVSCFXP/ using the same username and password used for SAU.

    I'll post a working log in a few mins.

  • Here is the last working log from a client connecting to CID SO63 before it updated to SAU 5.10.138

     

    Trace(2018-Jan-25 18:19:19): =========================
    Trace(2018-Jan-25 18:19:19): ALUpdate is starting.
    Trace(2018-Jan-25 18:19:19): AutoUpdate version: 5.7
    Trace(2018-Jan-25 18:19:19): Build : 210376
    Trace(2018-Jan-25 18:19:19): Command line : -ScheduledUpdate -NoGUI -RootPath "C:\Program Files (x86)\Sophos\AutoUpdate"
    Trace(2018-Jan-25 18:19:19): =========================
    Trace(2018-Jan-25 18:19:19): Process security set successfully
    Trace(2018-Jan-25 18:19:19): Product subscription is disabled: iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} action value is:0
    Trace(2018-Jan-25 18:19:19): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} has not been added.
    Trace(2018-Jan-25 18:19:19): Product subscription is disabled: iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} action value is:0
    Trace(2018-Jan-25 18:19:19): Product iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} has not been added.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} has been added.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is available from Sophos.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is not the Spam Rules package.
    Trace(2018-Jan-25 18:19:19): Product subscription is disabled: iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} action value is:0
    Trace(2018-Jan-25 18:19:19): Product iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} has not been added.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{3B758ED7-87C1-4e89-BDE1-F49DFF1249F6} has not been added.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} has been added.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is available from Sophos.
    Trace(2018-Jan-25 18:19:19): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is the Spam Rules package.
    Trace(2018-Jan-25 18:19:19): Computer is a not possible cluster
    Trace(2018-Jan-25 18:19:19): PureMessageDetector::AreSpamRulesRequired - Could not open registry on Software\Sophos\MMEx\Config\Global
    Trace(2018-Jan-25 18:19:19): ConfigurationImpl, considering PMSR 2.6: PureMessage not installed, PMSR package will not be updated without a subscription
    Trace(2018-Jan-25 18:19:19): Considering subscribed products.
    Trace(2018-Jan-25 18:19:19): Considering product {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-25 18:19:19): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is not already subscribed.
    Trace(2018-Jan-25 18:19:19): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} was added to the list.
    Trace(2018-Jan-25 18:19:19): Considering product {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-25 18:19:19): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is not already subscribed.
    Trace(2018-Jan-25 18:19:19): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} was added to the list.
    Trace(2018-Jan-25 18:19:19): Considering product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
    Trace(2018-Jan-25 18:19:19): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} is not already subscribed.
    Trace(2018-Jan-25 18:19:19): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} was added to the list.
    Trace(2018-Jan-25 18:19:19): Considering product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-25 18:19:19): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is not already subscribed.
    Trace(2018-Jan-25 18:19:19): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} was added to the list.
    Trace(2018-Jan-25 18:19:19): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is removable.
    Trace(2018-Jan-25 18:19:19): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is removable.
    Trace(2018-Jan-25 18:19:19): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is removable.
    Trace(2018-Jan-25 18:19:19): IPCBase::IPCBase: Initialising shared memory A32951C539924a12B3C8F2FDA5A268E4
    Trace(2018-Jan-25 18:19:19): IPCSender::ProcessSend started
    Trace(2018-Jan-25 18:19:19): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-25 18:19:19): RMSMessageHandler: ALUpdateStart
    Trace(2018-Jan-25 18:19:19): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-25 18:19:19): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-25 18:19:19): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-25 18:19:19): ALUpdate(AutoUpdate.Started):
    Trace(2018-Jan-25 18:19:19): UpdateCoordinator::UpdateNow: Entering
    Trace(2018-Jan-25 18:19:19): PopulateCache: Entering
    Trace(2018-Jan-25 18:19:19): UpdateCoordinator::UpdateNow: current platform is WIN_10_X64
    Trace(2018-Jan-25 18:19:19): ProductFactory::Create: SimpleProduct: {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-25 18:19:19): ProductFactory::Create: SimpleProduct: {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-25 18:19:19): ProductFactory::Create: SimpleProduct: {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-25 18:19:19): ProductFactory::Create: SAU Product
    Trace(2018-Jan-25 18:19:19): ProductFactory::Create: SimpleProduct: {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-25 18:19:19): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Entering
    Trace(2018-Jan-25 18:19:19): Processing CID update location: avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:19): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Finished. Number of new locations added: 0
    Trace(2018-Jan-25 18:19:19): UpdateCoordinator::UpdateNow: About to Sync list of products
    Trace(2018-Jan-25 18:19:19): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
    Trace(2018-Jan-25 18:19:19): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-25 18:19:19): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-25 18:19:19): Calling package_source_init
    Trace(2018-Jan-25 18:19:19): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-25 18:19:19): Custom certificate already present.
    Trace(2018-Jan-25 18:19:19): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-25 18:19:19): Remote connection over HTTP.
    Trace(2018-Jan-25 18:19:19): Read file master.upd (Remote).
    Trace(2018-Jan-25 18:19:19): Synchronised file root.upd (Local).
    Trace(2018-Jan-25 18:19:19): Synchronised file escdp.dat (Local).
    Trace(2018-Jan-25 18:19:19): No file expired_credential.dat.
    Trace(2018-Jan-25 18:19:19): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-25 18:19:19): Synchronised file ProductID.dat (Local).
    Trace(2018-Jan-25 18:19:19): ParseCustomerIDFile: completed: 0
    Trace(2018-Jan-25 18:19:19): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-25 18:19:19): CIDUpdateLocation::SyncProduct - Updating Product: SAVXP
    Trace(2018-Jan-25 18:19:19): CIDUpdate(SyncProduct.Start): SAVXP, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:19): Checksum found in master.upd matches cached cidsync.upd : da0ef42f. Skipping download
    Trace(2018-Jan-25 18:19:19): CIDUpdate(PrimarySuccess):
    Trace(2018-Jan-25 18:19:20): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 1
    Trace(2018-Jan-25 18:19:20): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 1
    Trace(2018-Jan-25 18:19:20): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
    Trace(2018-Jan-25 18:19:20): CIDUpdateLocation::SyncProduct - Updating Product: Sophos Endpoint Defense
    Trace(2018-Jan-25 18:19:20): CIDUpdate(SyncProduct.Start): Sophos Endpoint Defense, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:20): Checksum found in master.upd matches cached cidsync.upd : ec1b32a5. Skipping download
    Trace(2018-Jan-25 18:19:20): CIDUpdate(PrimarySuccess):
    Trace(2018-Jan-25 18:19:21): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
    Trace(2018-Jan-25 18:19:21): CIDUpdateLocation::SyncProduct - Updating Product: Sophos Network Threat Protection
    Trace(2018-Jan-25 18:19:21): CIDUpdate(SyncProduct.Start): Sophos Network Threat Protection, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:21): Checksum found in master.upd matches cached cidsync.upd : ca3f0de0. Skipping download
    Trace(2018-Jan-25 18:19:21): CIDUpdate(PrimarySuccess):
    Trace(2018-Jan-25 18:19:22): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
    Trace(2018-Jan-25 18:19:22): CIDUpdateLocation::SyncProduct - Updating Product: Sophos AutoUpdate
    Trace(2018-Jan-25 18:19:22): CIDUpdate(SyncProduct.Start): Sophos AutoUpdate, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:22): Checksum found in master.upd matches cached cidsync.upd : 2f3f6590. Skipping download
    Trace(2018-Jan-25 18:19:22): CIDUpdate(PrimarySuccess):
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::Prepare... entered
    Trace(2018-Jan-25 18:19:23): CheckManifest completed successfully
    Trace(2018-Jan-25 18:19:23): Custom Files found:
    Trace(2018-Jan-25 18:19:23): - C:\ProgramData\Sophos\AutoUpdate\cache\sau\sauconf.xml Checksum: 5fa332d058999f10992e8604bd1a705eb48c155c
    Trace(2018-Jan-25 18:19:23): (End of custom file list.)
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = sau productID = {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\sau.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::SyncProduct - Updating Product: Sophos System Protection
    Trace(2018-Jan-25 18:19:23): CIDUpdate(SyncProduct.Start): Sophos System Protection, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 18:19:23): Checksum found in master.upd matches cached cidsync.upd : 59d2646f. Skipping download
    Trace(2018-Jan-25 18:19:23): CIDUpdate(PrimarySuccess):
    Trace(2018-Jan-25 18:19:23): ALUpdate(DownloadEnded):
    Trace(2018-Jan-25 18:19:23): UpdateCoordinator::UpdateNow: About to Action list of products
    Trace(2018-Jan-25 18:19:23): SimpleProduct::DoAction isLater==false skipAction==false isUninstall==false m_lastUpdateSucceeded==true numfilestocahce 1 Actiontype SetupNot preinstalled product
    Trace(2018-Jan-25 18:19:23): Null update
    Trace(2018-Jan-25 18:19:23): ALUpdate(Action.Skipped): SAVXP
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate...
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = savxp productID = {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\savxp.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate complete.
    Trace(2018-Jan-25 18:19:23): Updating plugin cache for SAVXP
    Trace(2018-Jan-25 18:19:23): Successfully updated plugin cache for SAVXP
    Trace(2018-Jan-25 18:19:23): SimpleProduct::DoAction isLater==false skipAction==false isUninstall==false m_lastUpdateSucceeded==true numfilestocahce 1 Actiontype SetupNot preinstalled product
    Trace(2018-Jan-25 18:19:23): Null update
    Trace(2018-Jan-25 18:19:23): ALUpdate(Action.Skipped): Sophos Endpoint Defense
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate...
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = sed64 productID = {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\sed64.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate complete.
    Trace(2018-Jan-25 18:19:23): Updating plugin cache for Sophos Endpoint Defense
    Trace(2018-Jan-25 18:19:23): Successfully updated plugin cache for Sophos Endpoint Defense
    Trace(2018-Jan-25 18:19:23): SimpleProduct::DoAction isLater==false skipAction==false isUninstall==false m_lastUpdateSucceeded==true numfilestocahce 1 Actiontype SetupNot preinstalled product
    Trace(2018-Jan-25 18:19:23): Null update
    Trace(2018-Jan-25 18:19:23): ALUpdate(Action.Skipped): Sophos Network Threat Protection
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate...
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = ntp64 productID = {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\ntp64.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate complete.
    Trace(2018-Jan-25 18:19:23): Updating plugin cache for Sophos Network Threat Protection
    Trace(2018-Jan-25 18:19:23): Successfully updated plugin cache for Sophos Network Threat Protection
    Trace(2018-Jan-25 18:19:23): SimpleProduct::DoAction isLater==false skipAction==false isUninstall==false m_lastUpdateSucceeded==true numfilestocahce 1 Actiontype SetupNot preinstalled product
    Trace(2018-Jan-25 18:19:23): Null update
    Trace(2018-Jan-25 18:19:23): ALUpdate(Action.Skipped): Sophos AutoUpdate
    Trace(2018-Jan-25 18:19:23): Updating subscription information from product ID data.
    Trace(2018-Jan-25 18:19:23): Rigid name: F26F7EC0-1302-4DA7-8B6B-A5383051D41A
    Trace(2018-Jan-25 18:19:23): Version: 10.7.2.5.3692.1
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate...
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = sau productID = {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\sau.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate complete.
    Trace(2018-Jan-25 18:19:23): Updating plugin cache for Sophos AutoUpdate
    Trace(2018-Jan-25 18:19:23): Successfully updated plugin cache for Sophos AutoUpdate
    Trace(2018-Jan-25 18:19:23): SimpleProduct::DoAction isLater==false skipAction==false isUninstall==false m_lastUpdateSucceeded==true numfilestocahce 1 Actiontype SetupNot preinstalled product
    Trace(2018-Jan-25 18:19:23): Null update
    Trace(2018-Jan-25 18:19:23): ALUpdate(Action.Skipped): Sophos System Protection
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate...
    Trace(2018-Jan-25 18:19:23): CustomFileMap::CustomFileMap. CachePath = C:\ProgramData\Sophos\AutoUpdate\cache
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: Subfolder = ssp productID = {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File path = C:\ProgramData\Sophos\AutoUpdate\cache\ssp.custom
    Trace(2018-Jan-25 18:19:23): CustomFileMap::Read: File exists and appears valid.
    Trace(2018-Jan-25 18:19:23): CIDUpdateLocation::OnNullUpdate complete.
    Trace(2018-Jan-25 18:19:23): Updating plugin cache for Sophos System Protection
    Trace(2018-Jan-25 18:19:23): Successfully updated plugin cache for Sophos System Protection
    Trace(2018-Jan-25 18:19:24): RMSMessageHandler: ALUpdateEnd
    Trace(2018-Jan-25 18:19:24): Sending message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate" />
    Trace(2018-Jan-25 18:19:24): IPCSender::Write: Writing message:

  • And the first update after SAU 5.10 installed

    Trace(2018-Jan-25 20:31:48): =========================
    Trace(2018-Jan-25 20:31:48): ALUpdate is starting.
    Trace(2018-Jan-25 20:31:48): AutoUpdate version: 5.10
    Trace(2018-Jan-25 20:31:48): Build : 210356
    Trace(2018-Jan-25 20:31:48): Command line : -ScheduledUpdate -NoGUI -RootPath "C:\Program Files (x86)\Sophos\AutoUpdate"
    Trace(2018-Jan-25 20:31:48): =========================
    Trace(2018-Jan-25 20:31:48): Process security set successfully
    Trace(2018-Jan-25 20:31:48): Product subscription is disabled: iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} action value is:0
    Trace(2018-Jan-25 20:31:48): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} has not been added.
    Trace(2018-Jan-25 20:31:48): Product subscription is disabled: iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} action value is:0
    Trace(2018-Jan-25 20:31:48): Product iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} has not been added.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} has been added.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is available from Sophos.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is not the Spam Rules package.
    Trace(2018-Jan-25 20:31:48): Product subscription is disabled: iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} action value is:0
    Trace(2018-Jan-25 20:31:48): Product iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} has not been added.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{3B758ED7-87C1-4e89-BDE1-F49DFF1249F6} has not been added.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} has been added.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is available from Sophos.
    Trace(2018-Jan-25 20:31:48): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is the Spam Rules package.
    Trace(2018-Jan-25 20:31:48): Computer is a not possible cluster
    Trace(2018-Jan-25 20:31:48): PureMessageDetector::AreSpamRulesRequired - Could not open registry on Software\Sophos\MMEx\Config\Global
    Trace(2018-Jan-25 20:31:48): ConfigurationImpl, considering PMSR 2.6: PureMessage not installed, PMSR package will not be updated without a subscription
    Trace(2018-Jan-25 20:31:48): Considering subscribed products.
    Trace(2018-Jan-25 20:31:48): Considering product {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-25 20:31:48): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is not already subscribed.
    Trace(2018-Jan-25 20:31:48): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} was added to the list.
    Trace(2018-Jan-25 20:31:48): Considering product {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-25 20:31:48): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is not already subscribed.
    Trace(2018-Jan-25 20:31:48): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} was added to the list.
    Trace(2018-Jan-25 20:31:48): Considering product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
    Trace(2018-Jan-25 20:31:48): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} is not already subscribed.
    Trace(2018-Jan-25 20:31:48): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} was added to the list.
    Trace(2018-Jan-25 20:31:48): Considering product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-25 20:31:48): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is not already subscribed.
    Trace(2018-Jan-25 20:31:48): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} was added to the list.
    Trace(2018-Jan-25 20:31:48): Product {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E} is removable.
    Trace(2018-Jan-25 20:31:48): Product {8087796B-2289-4897-98A5-58FF23DAAFD0} is removable.
    Trace(2018-Jan-25 20:31:48): Product {1129226C-32AB-4B72-85E1-A9CC8DFBC859} is removable.
    Trace(2018-Jan-25 20:31:48): IPCBase::IPCBase: Initialising shared memory A32951C539924a12B3C8F2FDA5A268E4
    Trace(2018-Jan-25 20:31:48): IPCSender::ProcessSend started
    Trace(2018-Jan-25 20:31:48): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-25 20:31:48): RMSMessageHandler: ALUpdateStart
    Trace(2018-Jan-25 20:31:48): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-25 20:31:48): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
    Trace(2018-Jan-25 20:31:48): IPCSender::ProcessSend: No messages in queue, starting to wait
    Trace(2018-Jan-25 20:31:48): ALUpdate(AutoUpdate.Started):
    Trace(2018-Jan-25 20:31:48): UpdateCoordinator::UpdateNow: Entering
    Trace(2018-Jan-25 20:31:48): PopulateCache: Entering
    Trace(2018-Jan-25 20:31:48): UpdateCoordinator::UpdateNow: current platform is WIN_10_X64
    Trace(2018-Jan-25 20:31:48): ProductFactory::Create: SimpleProduct: {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-25 20:31:48): ProductFactory::Create: SimpleProduct: {1129226C-32AB-4B72-85E1-A9CC8DFBC859}
    Trace(2018-Jan-25 20:31:48): ProductFactory::Create: SimpleProduct: {8087796B-2289-4897-98A5-58FF23DAAFD0}
    Trace(2018-Jan-25 20:31:48): ProductFactory::Create: SAU Product
    Trace(2018-Jan-25 20:31:48): ProductFactory::Create: SimpleProduct: {F8FFD42E-47AC-4CFF-9E27-EC84ED62128E}
    Trace(2018-Jan-25 20:31:48): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Entering
    Trace(2018-Jan-25 20:31:48): Processing CID update location: avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 20:31:48): RelativeCidUpdateSourceLocator::AugmentUpdateSources: Finished. Number of new locations added: 0
    Trace(2018-Jan-25 20:31:48): UpdateCoordinator::UpdateNow: About to Sync list of products
    Trace(2018-Jan-25 20:31:48): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-25 20:31:48): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-25 20:31:48): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-25 20:31:48): Calling package_source_init
    Trace(2018-Jan-25 20:31:48): TrySyncProduct, Calling BeginSync
    Trace(2018-Jan-25 20:31:48): Custom certificate already present.
    Trace(2018-Jan-25 20:31:48): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\escdp.dat
    Trace(2018-Jan-25 20:31:48): Remote connection over HTTP.
    Trace(2018-Jan-25 20:31:48): File master.upd not found (Remote). Return code 0x80040f04
    Trace(2018-Jan-25 20:31:48): Unable to read file master.upd (Remote)
    Trace(2018-Jan-25 20:31:48): Unable to synchronise file root.upd.
    Trace(2018-Jan-25 20:31:48): Unable to synchronise file escdp.dat.
    Trace(2018-Jan-25 20:31:48): Unable to synchronise file expired_credential.dat.
    Trace(2018-Jan-25 20:31:48): CalculateChecksum. Processing file C:\ProgramData\Sophos\AutoUpdate\cache\ProductID.dat
    Trace(2018-Jan-25 20:31:48): Unable to synchronise file ProductID.dat.
    Trace(2018-Jan-25 20:31:48): File root.upd recovered.
    Trace(2018-Jan-25 20:31:48): File escdp.dat recovered.
    Trace(2018-Jan-25 20:31:48): File ProductID.dat recovered.
    Trace(2018-Jan-25 20:31:48): Unable to recover file expired_credential.dat.
    Trace(2018-Jan-25 20:31:48): Error -2147217660 in ReadCustomerIDFile
    Trace(2018-Jan-25 20:31:48): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {E17FE03B-0501-4aaa-BC69-0129D965F311}
    Trace(2018-Jan-25 20:31:48): CIDUpdateLocation::SyncProduct - Updating Product: SAVXP
    Trace(2018-Jan-25 20:31:48): CIDUpdate(SyncProduct.Start): SAVXP, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 20:31:48): CIDUpdateLocation::Sync - Updating from http CID: avupdate.XXXX.XX/.../savxp
    Trace(2018-Jan-25 20:31:48): CIDSync(CidSyncMessage):
    Trace(2018-Jan-25 20:31:48): CIDSync(CidSyncMessage):
    Trace(2018-Jan-25 20:31:48): CIDSyncCallback, SynchronisationTerminated - Code = -2147217660
    Trace(2018-Jan-25 20:31:48): CIDSyncCallback, SynchronisationTerminated - MapFile = C:\ProgramData\Sophos\AutoUpdate\cache\savxp.map
    Trace(2018-Jan-25 20:31:48): CIDUpdateLocation::SyncProduct: Failed to update product (SAVXP) from "avupdate.XXXX.XX/.../", Error is :CIDSYNC_E_FILESYNCERROR (Error during file download.)
    Trace(2018-Jan-25 20:31:48): CIDUpdate(CIDDownloadFailed): SAVXP, avupdate.XXXX.XX/.../
    Trace(2018-Jan-25 20:31:49): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 0
    Trace(2018-Jan-25 20:31:49): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 0
    Trace(2018-Jan-25 20:31:49): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
    Trace(2018-Jan-25 20:31:49): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
    Trace(2018-Jan-25 20:31:49): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
    Trace(2018-Jan-25 20:31:51): TrySyncProduct<cl

  • Hello Ahsan Amin,

    thanks for the logs. Strange, the only noticeable thing is that there's a custom file sauconf.xml but this should not cause such a failure. 
    clients are able to browse
    just wanted to make sure. Apparently they can - as you say that if you install 10.7.2 and let the endpoint update from S063 this works. So, the question is why once on 10.7.6/5.10 SAU reports this error. I have quite a number of endpoints successfully updating 10.7.6 from an HTTP IIS CID.

    Dunno if the log from the update that caused the upgrade together with the AutoUpdate setup and install logs would have some useful information. Guess you've sent them to Support. Personally I'd try to check what happens when it tries to download master.upd - Wireshark is the tool I use.

    Christian

  • Christian

     

    Thanks for your help. We've just noticed some clients which were previously not able to connect to update server are now connecting. The alc.log shows

     

    Last successful update at - 25/01/2018 20:46:59, this is when SAU updated from 5.7 to 5.10.

    Then every hourly update failing until - 29/01/2018 14:54:39

     

    Some clients are still failing to connect but this gives us hope.

  • The irony of a component failing it's one and only job is not  funny in this case ... SAU 5.10.139 appears to be flakey!

    Needless to say we have the same issue here, and its not limited to a HTTP CID. What we have seen is that on any machine where SUM is installed with SAU 5.10.139 the update/install process flunks 100% of the time. This manifests with a stalled download on the 3rd download in the sequence and a high CPU usage for the ALUpdate.exe process.  As the downloads never complete, the installs never begin, and thus prevent the updates. The only way to stop the process also appears to be via the Task Manager, it does not end on it's own. This occurs regardless of if the CID is being accessed via HTTP, UNC or locally.

    The SUM itself maintains the warehouse and the CID's fine, but in terms of it's own Endpoint it is toast.

    This has been seen on the following:

    • O/S: Windows Server 2008 R2 and Windows Server 2012 R2
    • SAU: 5.10.139
    • SUM: 1.6.2.186.

    Sophos needs to fix/pull it urgently and devise some method to kill the hung download process so an endpoint can successfully update itself. Visiting 1000's of endpoints is not an option.