I'll be honest and start with the fact that for me so far the support experience has been less than ideal, I have now dealt with two techs and other than very vague suggestion of "something your firewall may be doing" I have 0 real leads as to what's going on. I have over the weekend added packet captures from my firewall to the ticket, but to be honest I am not an expert so making sense of what's going on there is likely over my head.
Case# 5596176 in case anyone who reads this wishes to retain me as a customer.
Can anyone else here help? I believe my case has been escalated on friday to the global support team, but I have not heard from anyone since nor do I have the ability to call in.. (or do I?). Needless to say it's just frustrating having your #1 choice for antispam filtering be the cause of exchange rollout delays.
I do not use sophos for anything but puremessage/antispam duties on the exchange server, I don't have any enterprise client that downloads updates or client antivirus sophos apps etc..
My firewall is a Cisco ASA 5510, if it is the culprit I hope someone here or support can point me in the right direction, but clearly the communication starts and it is quite a simple firewall config too, no proxies for web traffic, no caching, no threat detection/IPS...
"ERROR: Could not find a source for updated packages" is the generic message in the update log
if I dig deeper under \programdata\ there is a log that shows more information: Trace(2015-Dec-21 12:01:27): EXCEPTION_ACCESS_VIOLATION at 0x720A8A2E
This is that full log for one attempt at update:
Trace(2015-Dec-21 12:51:26): ALUpdate started: -ScheduledUpdate -NoGUI -RootPath "C:\Program Files (x86)\Sophos\AutoUpdate"
Trace(2015-Dec-21 12:51:26): Process security set successfully
Trace(2015-Dec-21 12:51:26): Product subscription is disabled: iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} action value is:0
Trace(2015-Dec-21 12:51:26): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} has not been added.
Trace(2015-Dec-21 12:51:26): Product subscription is disabled: iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} action value is:0
Trace(2015-Dec-21 12:51:26): Product iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} has not been added.
Trace(2015-Dec-21 12:51:26): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} has been added.
Trace(2015-Dec-21 12:51:26): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is available from Sophos.
Trace(2015-Dec-21 12:51:26): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is not the Spam Rules package.
Trace(2015-Dec-21 12:51:26): Product subscription is disabled: iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} action value is:0
Trace(2015-Dec-21 12:51:26): Product iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} has not been added.
Trace(2015-Dec-21 12:51:26): Product iProductData.{3B758ED7-87C1-4e89-BDE1-F49DFF1249F6} has not been added.
Trace(2015-Dec-21 12:51:26): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} has been added.
Trace(2015-Dec-21 12:51:26): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is available from Sophos.
Trace(2015-Dec-21 12:51:26): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is the Spam Rules package.
Trace(2015-Dec-21 12:51:26): Computer is a not possible cluster
Trace(2015-Dec-21 12:51:26): PureMessageDetector::AreSpamRulesRequired - Could not open registry on Software\Sophos\MMEx\Config\Global
Trace(2015-Dec-21 12:51:26): ConfigurationImpl, considering PMSR 2.6: PureMessage not installed, PMSR package will not be updated without a subscription
Trace(2015-Dec-21 12:51:26): Considering subscribed products.
Trace(2015-Dec-21 12:51:26): Considering product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
Trace(2015-Dec-21 12:51:26): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} is not already subscribed.
Trace(2015-Dec-21 12:51:26): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} was added to the list.
Trace(2015-Dec-21 12:51:26): Considering product {B5E7E2A7-3B64-437D-801F-21CC9D67CC6D}
Trace(2015-Dec-21 12:51:26): Product {B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is not already subscribed.
Trace(2015-Dec-21 12:51:26): Product {B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is PureMessageSpamRules.
Trace(2015-Dec-21 12:51:26): Product {B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} was added to the list.
Trace(2015-Dec-21 12:51:26): Considering product {E17FE03B-0501-4aaa-BC69-0129D965F311}
Trace(2015-Dec-21 12:51:26): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2015-Dec-21 12:51:26): GenerateCustomerID: complete
Trace(2015-Dec-21 12:51:26): Computer is a not possible cluster
Trace(2015-Dec-21 12:51:26): PureMessageDetector::AreSpamRulesRequired - Could not open registry on Software\Sophos\MMEx\Config\Global
Trace(2015-Dec-21 12:51:26): IPCBase::IPCBase: Initialising shared memory A32951C539924a12B3C8F2FDA5A268E4
Trace(2015-Dec-21 12:51:26): RMSMessageHandler: ALUpdateStart
Trace(2015-Dec-21 12:51:26): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
Trace(2015-Dec-21 12:51:26): ALUpdate(AutoUpdate.Started):
Trace(2015-Dec-21 12:51:26): UpdateCoordinator::UpdateNow: Entering
Trace(2015-Dec-21 12:51:26): PopulateCache: Entering
Trace(2015-Dec-21 12:51:26): IPCSender::ProcessSend started
Trace(2015-Dec-21 12:51:26): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
Trace(2015-Dec-21 12:51:26): IPCSender::ProcessSend: No messages in queue, starting to wait
Trace(2015-Dec-21 12:51:26): IPCSender::ProcessSend: No messages in queue, starting to wait
Trace(2015-Dec-21 12:51:26): ProductFactory::Create: SimpleProduct: {E17FE03B-0501-4aaa-BC69-0129D965F311}
Trace(2015-Dec-21 12:51:26): ProductFactory::Create: SAU Product
Trace(2015-Dec-21 12:51:26): Could not open registry key: SOFTWARE\Sophos\AutoUpdate\Service\Subscription
Trace(2015-Dec-21 12:51:26): Using default subscription values...
Trace(2015-Dec-21 12:51:26): ProductFactory::Create: PMSR Product
Trace(2015-Dec-21 12:51:26): UpdateCoordinator::UpdateNow: About to Sync list of products
Trace(2015-Dec-21 12:51:26): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
Trace(2015-Dec-21 12:51:26): TrySyncProduct<class SDDS2::SULUpdateLocation>, Started:
Trace(2015-Dec-21 12:51:26): TrySyncProduct<class SDDS2::SULUpdateLocation>, creating update location
Trace(2015-Dec-21 12:51:26): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2015-Dec-21 12:51:26): Bandwidth limit set to 48
Trace(2015-Dec-21 12:51:26): Could not open registry key: SOFTWARE\Sophos\AutoUpdate\Service\Subscription
Trace(2015-Dec-21 12:51:26): Using default subscription values...
Trace(2015-Dec-21 12:51:26): SULUpdateLocation created!
Trace(2015-Dec-21 12:51:26): TrySyncProduct, Calling BeginSync
Trace(2015-Dec-21 12:51:26): SULUpdateLocation: BeginSync
Trace(2015-Dec-21 12:51:26): Path to decode files to: C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode
Trace(2015-Dec-21 12:51:26): SDDS2Update(SyncProduct.Start): Sophos Endpoint Security and Control, sophos
Trace(2015-Dec-21 12:51:26): Calling SULDownloader Setup...
Trace(2015-Dec-21 12:51:26): warehousePath: "C:\ProgramData\Sophos\AutoUpdate\data\warehouse"
Trace(2015-Dec-21 12:51:26): decodePath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode"
Trace(2015-Dec-21 12:51:26): certPath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir"
Trace(2015-Dec-21 12:51:26): server = sophos
Trace(2015-Dec-21 12:51:26): Adding Sophos Update Location: dci.sophosupd.com/update
Trace(2015-Dec-21 12:51:26): Adding Sophos Update Location: dci.sophosupd.net/update
Trace(2015-Dec-21 12:51:26): No manually configured proxy.
Trace(2015-Dec-21 12:51:26): SULDownloader setup successful.
Trace(2015-Dec-21 12:51:26): SubscriptionProvider: FALLBACK/RECOMMENDED/1.0
Trace(2015-Dec-21 12:51:27): EXCEPTION_ACCESS_VIOLATION at 0x720A8A2E
Trace(2015-Dec-21 12:51:27): Failed: SDDS2 CheckResubscription failed
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, Ended - 0
Trace(2015-Dec-21 12:51:27): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, Started:
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, creating update location
Trace(2015-Dec-21 12:51:27): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2015-Dec-21 12:51:27): Bandwidth limit set to 48
Trace(2015-Dec-21 12:51:27): Could not open registry key: SOFTWARE\Sophos\AutoUpdate\Service\Subscription
Trace(2015-Dec-21 12:51:27): Using default subscription values...
Trace(2015-Dec-21 12:51:27): SULUpdateLocation created!
Trace(2015-Dec-21 12:51:27): TrySyncProduct, Calling BeginSync
Trace(2015-Dec-21 12:51:27): SULUpdateLocation: BeginSync
Trace(2015-Dec-21 12:51:27): Path to decode files to: C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode
Trace(2015-Dec-21 12:51:27): SDDS2Update(SyncProduct.Start): Sophos Endpoint Security and Control, sophos
Trace(2015-Dec-21 12:51:27): Calling SULDownloader Setup...
Trace(2015-Dec-21 12:51:27): warehousePath: "C:\ProgramData\Sophos\AutoUpdate\data\warehouse"
Trace(2015-Dec-21 12:51:27): decodePath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode"
Trace(2015-Dec-21 12:51:27): certPath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir"
Trace(2015-Dec-21 12:51:27): server = sophos
Trace(2015-Dec-21 12:51:27): Adding Sophos Update Location: dci.sophosupd.com/update
Trace(2015-Dec-21 12:51:27): Adding Sophos Update Location: dci.sophosupd.net/update
Trace(2015-Dec-21 12:51:27): No manually configured proxy.
Trace(2015-Dec-21 12:51:27): SULDownloader setup successful.
Trace(2015-Dec-21 12:51:27): SubscriptionProvider: FALLBACK/RECOMMENDED/1.0
Trace(2015-Dec-21 12:51:27): EXCEPTION_ACCESS_VIOLATION at 0x720A8A2E
Trace(2015-Dec-21 12:51:27): Failed: SDDS2 CheckResubscription failed
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, Ended - 0
Trace(2015-Dec-21 12:51:27): UpdateLocationFacade::SyncProduct: Last Update Mechanism = Unknown
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, Started:
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, creating update location
Trace(2015-Dec-21 12:51:27): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2015-Dec-21 12:51:27): Bandwidth limit set to 48
Trace(2015-Dec-21 12:51:27): Could not open registry key: SOFTWARE\Sophos\AutoUpdate\Service\Subscription
Trace(2015-Dec-21 12:51:27): Using default subscription values...
Trace(2015-Dec-21 12:51:27): SULUpdateLocation created!
Trace(2015-Dec-21 12:51:27): TrySyncProduct, Calling BeginSync
Trace(2015-Dec-21 12:51:27): SULUpdateLocation: BeginSync
Trace(2015-Dec-21 12:51:27): Path to decode files to: C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode
Trace(2015-Dec-21 12:51:27): SDDS2Update(SyncProduct.Start): Sophos Endpoint Security and Control, sophos
Trace(2015-Dec-21 12:51:27): Calling SULDownloader Setup...
Trace(2015-Dec-21 12:51:27): warehousePath: "C:\ProgramData\Sophos\AutoUpdate\data\warehouse"
Trace(2015-Dec-21 12:51:27): decodePath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir\decode"
Trace(2015-Dec-21 12:51:27): certPath: "C:\ProgramData\Sophos\AutoUpdate\cache\sophos_autoupdate1.dir"
Trace(2015-Dec-21 12:51:27): server = sophos
Trace(2015-Dec-21 12:51:27): Adding Sophos Update Location: dci.sophosupd.com/update
Trace(2015-Dec-21 12:51:27): Adding Sophos Update Location: dci.sophosupd.net/update
Trace(2015-Dec-21 12:51:27): No manually configured proxy.
Trace(2015-Dec-21 12:51:27): SULDownloader setup successful.
Trace(2015-Dec-21 12:51:27): SubscriptionProvider: FALLBACK/RECOMMENDED/1.0
Trace(2015-Dec-21 12:51:27): EXCEPTION_ACCESS_VIOLATION at 0x720A8A2E
Trace(2015-Dec-21 12:51:27): Failed: SDDS2 CheckResubscription failed
Trace(2015-Dec-21 12:51:27): TrySyncProduct<class SDDS2::SULUpdateLocation>, Ended - 0
Trace(2015-Dec-21 12:51:27): ALUpdate():
Trace(2015-Dec-21 12:51:27): ALUpdate(DownloadEnded):
Trace(2015-Dec-21 12:51:27): UpdateCoordinator::UpdateNow: About to Action list of products
Trace(2015-Dec-21 12:51:27): RMSMessageHandler: ALUpdateEnd
Trace(2015-Dec-21 12:51:27): Sending message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate"><ErrorMessage><ID></ID><StringID>113</StringID><Sender>ALUpdate</Sender></ErrorMessage><ReadableMessage>ERROR: Could not find a source for updated packages</ReadableMessage></Config>
Trace(2015-Dec-21 12:51:27): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate"><ErrorMessage><ID></ID><StringID>113</StringID><Sender>ALUpdate</Sender></ErrorMessage><ReadableMessage>ERROR: Could not find a source for updated packages</ReadableMessage></Config>
Trace(2015-Dec-21 12:51:27): IPCSender::ProcessSend: Listener not ready starting to wait
Trace(2015-Dec-21 12:51:28): IPCSender::ProcessSend exiting
This thread was automatically locked due to age.
