Sophos UTM - Home Edition
Version 9.509-3
I installed the client on two new Win 10 laptops. When I looked I saw "not protected" for their status on the UTM. So I checked another existing client. That one had updates failing starting September 12, 2018. A restart of the UTM fixed the updates on the older install of the client.
Updates fail on the new client, first I will share what I think are the key lines in the log and then you will see the full log for the update session.
Key lines:
2018-09-17T02:20:52.213Z [ 9836] INFO SUL-Log [I19464] Syncing file 39c1663d6a8001cf7d0fb196a717070ex000.dat: 156456 bytes: savxp/ConfigureSAV.exe
2018-09-17T02:20:53.389Z [ 9836] INFO SUL-Log [I19464] File 39c1663d6a8001cf7d0fb196a717070ex000.dat: sync failed
2018-09-17T02:20:54.156Z [ 9836] ERROR SUL-Log [E35582] [DetailedException: File copy failed. [File: '39c1663d6a8001cf7d0fb196a717070ex000.dat' ] [From: 'adapter|{adapter|{adapter|{http|http://d1.sophosupd.com/update/|}|}|}|' ] [To: 'file|C:/ProgramData/Sophos/AutoUpdate/data/warehouse|' ] ]
2018-09-17T02:20:54.206Z [ 9836] ERROR SDDSDownloader::ReportSyncFailure Failed to synchronise
Full Log:
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain =========================
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain SophosUpdate is starting.
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain AutoUpdate version : 5.4.0.751
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain SophosUpdate version : 5.4.0.425
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain Build : 210399
2018-09-17T02:20:36.477Z [ 9836] INFO WinMain =========================
2018-09-17T02:20:36.477Z [ 9836] INFO Environment::Print Platform ID: WIN_10_X64
2018-09-17T02:20:36.477Z [ 9836] INFO Environment::Print Platform upgraded: 0
2018-09-17T02:20:36.477Z [ 9836] INFO Environment::Print Subscription: cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED 1
2018-09-17T02:20:36.477Z [ 9836] INFO Environment::Print Subscriptions changed: 1
2018-09-17T02:20:36.477Z [ 9836] INFO Environment::Print Features:
2018-09-17T02:20:36.478Z [ 9836] INFO Environment::Print Features changed: 1
2018-09-17T02:20:36.478Z [ 9836] INFO WinMain Set process security
2018-09-17T02:20:36.478Z [ 9836] INFO WinMain Initialise COM.
2018-09-17T02:20:36.479Z [ 9836] INFO WinMain Load config.
2018-09-17T02:20:36.482Z [ 9836] INFO WinMain Create registry reporter.
2018-09-17T02:20:36.482Z [ 9836] INFO WinMain Create platform reporter.
2018-09-17T02:20:36.482Z [ 9836] INFO WinMain Create features reporter.
2018-09-17T02:20:36.482Z [ 9836] INFO WinMain Create subscription reporter.
2018-09-17T02:20:36.482Z [ 9836] INFO WinMain Load state.
2018-09-17T02:20:36.482Z [ 9836] INFO StatePersister::Load Loading state file C:\ProgramData\Sophos\AutoUpdate\data\status\SophosUpdateStatus.xml
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetInstalledThumbprint Set installed thumbprint for 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 to .
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetDownloadedThumbprint Set downloaded thumbprint for 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 to .
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetInstalledThumbprint Set installed thumbprint for 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 to .
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetDownloadedThumbprint Set downloaded thumbprint for 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 to .
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetInstalledThumbprint Set installed thumbprint for E17FE03B-0501-4aaa-BC69-0129D965F311 to .
2018-09-17T02:20:36.483Z [ 9836] INFO ComponentState::SetDownloadedThumbprint Set downloaded thumbprint for E17FE03B-0501-4aaa-BC69-0129D965F311 to .
2018-09-17T02:20:36.484Z [ 9836] INFO WinMain Create progress reporter.
2018-09-17T02:20:36.506Z [ 9836] INFO WinMain Create language neutral logger.
2018-09-17T02:20:36.506Z [ 9836] INFO WinMain Create Update cache evaluator.
2018-09-17T02:20:36.506Z [ 9836] INFO WinMain Create downloader.
2018-09-17T02:20:36.512Z [ 9836] INFO WinMain Create installer.
2018-09-17T02:20:36.512Z [ 9836] INFO WinMain Create adapter writer.
2018-09-17T02:20:36.512Z [ 9836] INFO IPCBase::IPCBase IPCBase::IPCBase: Connected to shared memory A32951C539924a12B3C8F2FDA5A268E4
2018-09-17T02:20:36.512Z [ 9836] INFO WinMain Create completion reporter.
2018-09-17T02:20:36.512Z [ 9836] INFO WinMain Create update logic.
2018-09-17T02:20:36.512Z [ 9836] INFO WinMain Performing update.
2018-09-17T02:20:36.512Z [ 9872] INFO `anonymous-namespace'::SenderThreadFn::operator() Sender thread started.
2018-09-17T02:20:36.512Z [ 9836] INFO UpdateLogic::Update Reporting update start.
2018-09-17T02:20:36.512Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend started
2018-09-17T02:20:36.512Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend: No messages in queue, starting to wait
2018-09-17T02:20:36.518Z [ 9836] INFO IPCSender::Write IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
2018-09-17T02:20:36.519Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
2018-09-17T02:20:36.519Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend: No messages in queue, starting to wait
2018-09-17T02:20:36.589Z [ 9836] INFO UpdateLogic::SyncAndInstall Syncing products.
2018-09-17T02:20:36.590Z [ 9836] INFO SourceSelector::getCandidateProxies No manually configured proxy.
2018-09-17T02:20:36.590Z [ 9836] INFO WindowsProxyDiscoveryWrapper::GetDefaultProxyConfiguration WinHttp default proxy not set
2018-09-17T02:20:36.614Z [ 9972] WARN WindowsProxyDiscoveryWrapper::GetProxyForUrl Failed to get the automatic proxy configuration. The error code was 12180.
2018-09-17T02:20:36.614Z [ 9836] INFO SourceSelector::evaluate Trying update location: dci.sophosupd.com/update with proxy:
2018-09-17T02:20:36.908Z [ 9836] INFO SourceSelector::analyze Selected update location: dci.sophosupd.com/update with proxy:
2018-09-17T02:20:36.909Z [ 9836] INFO SDDSDownloader::SyncInternal Username: 53557YNJ9E
2018-09-17T02:20:36.909Z [ 9836] INFO SDDSDownloader::SyncInternal Filename: 1620bd8982c1fd7471331da59705f264
2018-09-17T02:20:36.911Z [ 9836] INFO CacheEvaluator::evaluate No update caches configured
2018-09-17T02:20:36.911Z [ 9836] INFO SDDSDownloader::SyncInternal Adding Sophos Location: dci.sophosupd.com/update
2018-09-17T02:20:36.914Z [ 9836] INFO SUL-Log [I40394] Downloading customer file from sophos:1:1
2018-09-17T02:20:37.063Z [ 9836] INFO SUL-Log [I40395] Downloaded customer file; fetching catalogues from sophos:1:1...
2018-09-17T02:20:37.279Z [ 9836] INFO SUL-Log [I40395] Successfully fetched catalogues from sophos:1:1
2018-09-17T02:20:37.280Z [ 9836] INFO SDDSDownloader::CreatePackageDistributionInformation Including 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 2.0.2.3: mcsep/*
2018-09-17T02:20:37.280Z [ 9836] INFO SDDSDownloader::CreatePackageDistributionInformation Including E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128: savxp/*
2018-09-17T02:20:37.281Z [ 9836] INFO SDDSDownloader::CreatePackageDistributionInformation Including 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 5.4.0.751: sau/*
2018-09-17T02:20:37.281Z [ 9836] INFO SDDSDownloader::CreatePackageDistributionInformation Skipping ENG 3.70.2.0: not deployable
2018-09-17T02:20:37.281Z [ 9836] INFO SDDSDownloader::SyncInternal Beginning synchronise
2018-09-17T02:20:37.288Z [ 9836] INFO SUL-Log [I96736] sdds.UTM_11013.2: adding primary package cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED baseVersion=1
2018-09-17T02:20:37.288Z [ 9836] INFO SUL-Log [I95020] sdds.UTM_11013.2: looking for packages included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=
2018-09-17T02:20:37.288Z [ 9836] INFO SUL-Log [I45378] sdds.UTM_11013.2: found included product 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 2.0.2.3 path=mcsep baseVersion= [included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=]
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I45378] sdds.UTM_11013.2: found included product ENG 3.70.2.0 path=savxp baseVersion= [included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=]
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I45378] sdds.UTM_11013.2: found included product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp baseVersion= [included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=]
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I45378] sdds.UTM_11013.2: found included product 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 5.4.0.751 path=sau baseVersion= [included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=]
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I22529] sdds.UTM_11013.2: looking for supplements included from product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I95020] sdds.UTM_11013.2: looking for packages included from product 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 2.0.2.3 path=mcsep
2018-09-17T02:20:37.289Z [ 9836] INFO SUL-Log [I22529] sdds.UTM_11013.2: looking for supplements included from product 8580B6E7-AD8F-4c42-8085-ABD5765C98C5 2.0.2.3 path=mcsep
2018-09-17T02:20:37.290Z [ 9836] INFO SUL-Log [I95020] sdds.UTM_11013.2: looking for packages included from product ENG 3.70.2.0 path=savxp
2018-09-17T02:20:37.290Z [ 9836] INFO SUL-Log [I22529] sdds.UTM_11013.2: looking for supplements included from product ENG 3.70.2.0 path=savxp
2018-09-17T02:20:38.994Z [ 9836] INFO SUL-Log [I49502] sdds.VDB_supp.xml: found supplement VDL LATEST path=savxp baseVersion= [included from product ENG 3.70.2.0 path=savxp]
2018-09-17T02:20:38.994Z [ 9836] INFO SUL-Log [I95020] sdds.UTM_11013.2: looking for packages included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp
2018-09-17T02:20:38.995Z [ 9836] INFO SUL-Log [I22529] sdds.UTM_11013.2: looking for supplements included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp
2018-09-17T02:20:40.569Z [ 9836] INFO SUL-Log [I49502] sdds.APPFEED_d1.xml: found supplement USERAPPFEED LATEST path=savxp baseVersion= [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:42.132Z [ 9836] INFO SUL-Log [I49502] sdds.CRTSUPP.xml: found supplement 97B6A561-5F87-4A2E-A4FE-177F48D8899F RECOMMENDED path=savxp/crt baseVersion= [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:43.746Z [ 9836] INFO SUL-Log [I49502] sdds.SAVCNTRL.xml: found supplement SAVCONTROLLINE UTM path=savxp baseVersion= [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:45.310Z [ 9836] INFO SUL-Log [I49502] sdds.sdu.xml: found supplement SDU LATEST path=savxp baseVersion= [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:46.884Z [ 9836] INFO SUL-Log [I49502] sdds.sxl_supp.xml: found supplement SXLSUP LATEST path=savxp baseVersion=2 [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:48.456Z [ 9836] INFO SUL-Log [I49502] sdds.hips.xml: found supplement HIPS LATEST_UTM path=savxp baseVersion= [included from product E17FE03B-0501-4aaa-BC69-0129D965F311 10.7.6.128 path=savxp]
2018-09-17T02:20:48.456Z [ 9836] INFO SUL-Log [I95020] sdds.UTM_11013.2: looking for packages included from product 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 5.4.0.751 path=sau
2018-09-17T02:20:48.457Z [ 9836] INFO SUL-Log [I22529] sdds.UTM_11013.2: looking for supplements included from product 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 5.4.0.751 path=sau
2018-09-17T02:20:50.022Z [ 9836] INFO SUL-Log [I49502] sdds.TELEMSUPP.xml: found supplement TELEMSUP RECOMMENDED path=sau baseVersion= [included from product 9BF40A4E-23AE-48be-9974-5A1F261DBEE8 5.4.0.751 path=sau]
2018-09-17T02:20:50.022Z [ 9836] INFO SUL-Log [I95020] sdds.VDB_supp.xml: looking for packages included from product VDL LATEST path=savxp
2018-09-17T02:20:50.022Z [ 9836] INFO SUL-Log [I22529] sdds.VDB_supp.xml: looking for supplements included from product VDL LATEST path=savxp
2018-09-17T02:20:51.813Z [ 9836] INFO SUL-Log [I49502] sdds.data0910.xml: found supplement IDE555 LATEST path=savxp baseVersion= [included from product VDL LATEST path=savxp]
2018-09-17T02:20:51.813Z [ 9836] INFO SUL-Log [I95020] sdds.APPFEED_d1.xml: looking for packages included from product USERAPPFEED LATEST path=savxp
2018-09-17T02:20:51.813Z [ 9836] INFO SUL-Log [I22529] sdds.APPFEED_d1.xml: looking for supplements included from product USERAPPFEED LATEST path=savxp
2018-09-17T02:20:51.813Z [ 9836] INFO SUL-Log [I95020] sdds.CRTSUPP.xml: looking for packages included from product 97B6A561-5F87-4A2E-A4FE-177F48D8899F RECOMMENDED path=savxp/crt
2018-09-17T02:20:51.813Z [ 9836] INFO SUL-Log [I22529] sdds.CRTSUPP.xml: looking for supplements included from product 97B6A561-5F87-4A2E-A4FE-177F48D8899F RECOMMENDED path=savxp/crt
2018-09-17T02:20:51.814Z [ 9836] INFO SUL-Log [I95020] sdds.SAVCNTRL.xml: looking for packages included from product SAVCONTROLLINE UTM path=savxp
2018-09-17T02:20:51.814Z [ 9836] INFO SUL-Log [I22529] sdds.SAVCNTRL.xml: looking for supplements included from product SAVCONTROLLINE UTM path=savxp
2018-09-17T02:20:51.814Z [ 9836] INFO SUL-Log [I95020] sdds.sdu.xml: looking for packages included from product SDU LATEST path=savxp
2018-09-17T02:20:51.814Z [ 9836] INFO SUL-Log [I22529] sdds.sdu.xml: looking for supplements included from product SDU LATEST path=savxp
2018-09-17T02:20:51.814Z [ 9836] INFO SUL-Log [I95020] sdds.sxl_supp.xml: looking for packages included from product SXLSUP LATEST path=savxp
2018-09-17T02:20:51.815Z [ 9836] INFO SUL-Log [I22529] sdds.sxl_supp.xml: looking for supplements included from product SXLSUP LATEST path=savxp
2018-09-17T02:20:51.815Z [ 9836] INFO SUL-Log [I95020] sdds.hips.xml: looking for packages included from product HIPS LATEST_UTM path=savxp
2018-09-17T02:20:51.815Z [ 9836] INFO SUL-Log [I22529] sdds.hips.xml: looking for supplements included from product HIPS LATEST_UTM path=savxp
2018-09-17T02:20:51.815Z [ 9836] INFO SUL-Log [I95020] sdds.TELEMSUPP.xml: looking for packages included from product TELEMSUP RECOMMENDED path=sau
2018-09-17T02:20:51.816Z [ 9836] INFO SUL-Log [I22529] sdds.TELEMSUPP.xml: looking for supplements included from product TELEMSUP RECOMMENDED path=sau
2018-09-17T02:20:51.817Z [ 9836] INFO SUL-Log [I95020] sdds.data0910.xml: looking for packages included from product IDE555 LATEST path=savxp
2018-09-17T02:20:51.817Z [ 9836] INFO SUL-Log [I22529] sdds.data0910.xml: looking for supplements included from product IDE555 LATEST path=savxp
2018-09-17T02:20:51.912Z [ 9836] INFO SUL-Log [I49502] sdds.data0910.xml: found supplement IDE556 LATEST path=savxp baseVersion= [included from product IDE555 LATEST path=savxp]
2018-09-17T02:20:51.913Z [ 9836] INFO SUL-Log [I95020] sdds.data0910.xml: looking for packages included from product IDE556 LATEST path=savxp
2018-09-17T02:20:51.914Z [ 9836] INFO SUL-Log [I22529] sdds.data0910.xml: looking for supplements included from product IDE556 LATEST path=savxp
2018-09-17T02:20:52.004Z [ 9836] INFO SUL-Log [I49502] sdds.data0910.xml: found supplement IDE557 LATEST path=savxp baseVersion= [included from product IDE556 LATEST path=savxp]
2018-09-17T02:20:52.004Z [ 9836] INFO SUL-Log [I95020] sdds.data0910.xml: looking for packages included from product IDE557 LATEST path=savxp
2018-09-17T02:20:52.005Z [ 9836] INFO SUL-Log [I22529] sdds.data0910.xml: looking for supplements included from product IDE557 LATEST path=savxp
2018-09-17T02:20:52.104Z [ 9836] INFO SUL-Log [I49502] sdds.data0910.xml: found supplement IDE558 LATEST path=savxp baseVersion= [included from product IDE557 LATEST path=savxp]
2018-09-17T02:20:52.105Z [ 9836] INFO SUL-Log [I95020] sdds.data0910.xml: looking for packages included from product IDE558 LATEST path=savxp
2018-09-17T02:20:52.106Z [ 9836] INFO SUL-Log [I22529] sdds.data0910.xml: looking for supplements included from product IDE558 LATEST path=savxp
2018-09-17T02:20:52.106Z [ 9836] INFO SUL-Log [I19463] Syncing product cd2a5386-f08c-42b1-8d98-40240059e361 RECOMMENDED path=
2018-09-17T02:20:52.203Z [ 9836] INFO SUL-Log [I19463] Product download size 63856261 bytes
2018-09-17T02:20:52.213Z [ 9836] INFO SUL-Log [I19464] Syncing file 39c1663d6a8001cf7d0fb196a717070ex000.dat: 156456 bytes: savxp/ConfigureSAV.exe
2018-09-17T02:20:53.389Z [ 9836] INFO SUL-Log [I19464] File 39c1663d6a8001cf7d0fb196a717070ex000.dat: sync failed
2018-09-17T02:20:54.156Z [ 9836] ERROR SUL-Log [E35582] [DetailedException: File copy failed. [File: '39c1663d6a8001cf7d0fb196a717070ex000.dat' ] [From: 'adapter|{adapter|{adapter|{http|http://d1.sophosupd.com/update/|}|}|}|' ] [To: 'file|C:/ProgramData/Sophos/AutoUpdate/data/warehouse|' ] ]
2018-09-17T02:20:54.206Z [ 9836] ERROR SDDSDownloader::ReportSyncFailure Failed to synchronise
2018-09-17T02:20:54.215Z [ 9836] INFO UpdateLogic::SyncAndInstall Saving state.
2018-09-17T02:20:54.216Z [ 9836] INFO StatePersister::Save Overwriting state file C:\ProgramData\Sophos\AutoUpdate\data\status\SophosUpdateStatus.xml
2018-09-17T02:20:54.219Z [ 9836] INFO UpdateLogic::SyncAndInstall Skipping product install as Sync failed.
2018-09-17T02:20:55.267Z [ 9836] INFO IPCSender::Write IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate"><ErrorMessage><ID>SDDSDownloadFailed</ID><StringID>107</StringID><Sender>SophosUpdate</Sender><Insert>cd2a5386-f08c-42b1-8d98-40240059e361</Insert><Insert>dci.sophosupd.com/.../ErrorMessage><ReadableMessage>ERROR: Download of cd2a5386-f08c-42b1-8d98-40240059e361 failed from server dci.sophosupd.com/.../Config>
2018-09-17T02:20:55.268Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate"><ErrorMessage><ID>SDDSDownloadFailed</ID><StringID>107</StringID><Sender>SophosUpdate</Sender><Insert>cd2a5386-f08c-42b1-8d98-40240059e361</Insert><Insert>dci.sophosupd.com/.../ErrorMessage><ReadableMessage>ERROR: Download of cd2a5386-f08c-42b1-8d98-40240059e361 failed from server dci.sophosupd.com/.../Config>
2018-09-17T02:20:55.268Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend: No messages in queue, starting to wait
2018-09-17T02:20:55.269Z [ 9836] INFO WinMain SophosUpdate has completed with the result 2.
2018-09-17T02:20:56.271Z [ 9872] INFO IPCSender::ProcessSend IPCSender::ProcessSend exiting
2018-09-17T02:20:56.271Z [ 9872] INFO `anonymous-namespace'::SenderThreadFn::operator() Sender thread finished.
2018-09-17T02:20:56.272Z [ 9836] INFO StatePersister::Save Overwriting state file C:\ProgramData\Sophos\AutoUpdate\data\status\SophosUpdateStatus.xml
This thread was automatically locked due to age.