Guest User!

You are not Sophos Staff.

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

"Updating" never finishes

I see this on a few clients, the definitions are totally out of date and if you click "Update Now" it simply sits saying "Updating" with nothing happening.

The "Sophos AutoUpdate" service is running and I can see the alsvc.exe process running.

We have an internal update proxy/cache running on a server and most clients update from the Internet absolutely fine.

The SophosUpdate.log shows:

2017-06-06T14:09:57.988Z [ 9120] INFO WinMain =========================
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain SophosUpdate is starting.
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain AutoUpdate version : 5.5.0.26
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain SophosUpdate version : 5.5.0.141
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain Build : 203431
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain =========================
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Platform ID: WIN_7_X64
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Platform upgraded: 0
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Subscription: WindowsCloudNextGen RECOMMENDED 11
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Subscription: WindowsCloudHitmanProAlert RECOMMENDED 1
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Subscriptions changed: 0
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Features: APPCNTRL AV CORE DLP DVCCNTRL EFW HBT NTP SAV SDU WEBCNTRL
2017-06-06T14:09:57.994Z [ 9120] INFO Environment::Print Features changed: 1
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain Set process security
2017-06-06T14:09:57.994Z [ 9120] INFO WinMain Initialise COM.
2017-06-06T14:09:57.995Z [ 9120] INFO WinMain Load config.
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Create registry reporter.
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Create platform reporter.
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Create features reporter.
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Create subscription reporter.
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Load state.
2017-06-06T14:09:57.997Z [ 9120] INFO StatePersister::Load Loading state file C:\ProgramData\Sophos\AutoUpdate\data\status\SophosUpdateStatus.xml
2017-06-06T14:09:57.997Z [ 9120] INFO WinMain Create progress reporter.
2017-06-06T14:09:58.002Z [ 9120] INFO WinMain Create language neutral logger.
2017-06-06T14:09:58.002Z [ 9120] INFO WinMain Create Update cache evaluator.
2017-06-06T14:09:58.002Z [ 9120] INFO WinMain Create downloader.
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Create Health event manager.
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Create installer.
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Create adapter writer.
2017-06-06T14:09:58.005Z [ 9120] INFO IPCBase::IPCBase IPCBase::IPCBase: Connected to shared memory A32951C539924a12B3C8F2FDA5A268E4
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Create completion reporter.
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Create update logic.
2017-06-06T14:09:58.005Z [ 9120] INFO WinMain Performing update.
2017-06-06T14:09:58.005Z [ 9120] INFO UpdateLogic::Update Reporting update start.
2017-06-06T14:09:58.005Z [ 5216] INFO `anonymous-namespace'::SenderThreadFn::operator() Sender thread started.
2017-06-06T14:09:58.005Z [ 5216] INFO IPCSender::ProcessSend IPCSender::ProcessSend started
2017-06-06T14:09:58.005Z [ 5216] INFO IPCSender::ProcessSend IPCSender::ProcessSend: No messages in queue, starting to wait
2017-06-06T14:09:58.006Z [ 9120] INFO IPCSender::Write IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
2017-06-06T14:09:58.006Z [ 5216] INFO IPCSender::ProcessSend IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
2017-06-06T14:09:58.006Z [ 5216] INFO IPCSender::ProcessSend IPCSender::ProcessSend: No messages in queue, starting to wait
2017-06-06T14:09:58.007Z [ 9120] INFO UpdateLogic::SyncAndInstall Syncing products.
2017-06-06T14:09:58.007Z [ 9120] INFO SourceSelector::getCandidateProxies No manually configured proxy.
2017-06-06T14:09:58.007Z [ 9120] INFO WindowsProxyDiscoveryWrapper::GetDefaultProxyConfiguration WinHttp default proxy not set
2017-06-06T14:09:58.024Z [ 4812] WARN WindowsProxyDiscoveryWrapper::GetProxyForUrl Failed to get the automatic proxy configuration. The error code was 12180.
2017-06-06T14:09:58.025Z [ 9120] INFO SourceSelector::evaluate Trying update location: dci.sophosupd.com/update with proxy: <direct; no proxy>
2017-06-06T14:09:58.351Z [ 9120] INFO SourceSelector::analyze Selected update location: dci.sophosupd.com/update with proxy:
2017-06-06T14:09:58.351Z [ 9120] INFO SDDSDownloader::SyncInternal Username: AJHDFDDOGF
2017-06-06T14:09:58.351Z [ 9120] INFO SDDSDownloader::SyncInternal Filename: 54cfa77f5dcb0d5beeea2bf6f8e94f42
2017-06-06T14:09:58.352Z [ 9120] INFO CacheEvaluator::evaluate Analyzing whether to update from Sophos CDN or update cache
2017-06-06T14:09:58.353Z [ 9120] INFO CacheEvaluator::evaluateSophos Checking access to Sophos CDN...
2017-06-06T14:09:58.423Z [ 9120] INFO CacheEvaluator::evaluateSophos Successfully connected to Sophos CDN
2017-06-06T14:09:58.423Z [ 9120] INFO CacheEvaluator::evaluateSophos Sophos response time: 69ms
2017-06-06T14:09:58.423Z [ 9120] INFO CacheEvaluator::evaluate Sophos response time after application of tuning parameters: 169ms
2017-06-06T14:09:58.423Z [ 9120] INFO CacheEvaluator::evaluateCache Checking access to update cache: sophoscache.ourdomain.com:8191
2017-06-06T14:09:58.450Z [ 9120] INFO CacheEvaluator::evaluateCache Successfully connected to cache
2017-06-06T14:09:58.450Z [ 9120] INFO CacheEvaluator::evaluateCache Cache response time: 26ms
2017-06-06T14:09:58.450Z [ 9120] INFO CacheEvaluator::evaluate Analysis complete - Using update cache: sophoscache.ourdomain.com:8191
2017-06-06T14:09:58.450Z [ 9120] INFO SDDSDownloader::SyncInternal Updating from cache: sophoscache.ourdomain.com:8191
2017-06-06T14:09:58.450Z [ 9120] INFO SDDSDownloader::SyncInternal Delta compression enabled



This thread was automatically locked due to age.
  • Is that really the end of the log or does it continue beyond the line:

    SyncInternal Delta compression enabled

    Out of interest, is there anything in the System/Application event log when it ends?  

    Could the SophosUpdate.exe process (this is the one that the alsvc.exe process spawns to do the update) be crashing out which would explain the abrupt end if the log is anything to go by?

    Does the SophosUpdate.exe process just hang.  It should just get created by the service, perform the update and exit.

    Regards,

    Jak

  • I have a similar issue. I do not have an update cache server, all clients go to the Internet for updates. Most work just fine. I have several that fail to update and when I look at the client the update status is "Updating" indefinitely. If I restart the client computer it will update successfully, but within a day or two will revert back to failing to update. This has been a reoccurring issue for several months.

    Here is an excerpt from the last update attempt, this is the entire entry. From SophosUpdate.log

    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain =========================
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain SophosUpdate is starting.
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain AutoUpdate version : 5.8.407
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain SophosUpdate version : 5.8.259
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain Build : 206630
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain =========================
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Platform ID: WIN_10_X64
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Platform upgraded: 0
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Subscription: WindowsCloudNextGen RECOMMENDED 11
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Subscription: WindowsCloudClean RECOMMENDED 1
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Subscription: WindowsCloudAV RECOMMENDED 11
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Subscription: WindowsCloudHitmanProAlert RECOMMENDED 1
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Subscriptions changed: 0
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Features: APPCNTRL AV CLEAN CORE DLP DVCCNTRL EFW HBT NTP SAV SDU WEBCNTRL XPD
    2017-11-21T14:17:09.978Z [ 5532] INFO Environment::Print Features changed: 0
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain Set process security
    2017-11-21T14:17:09.978Z [ 5532] INFO WinMain Initialise COM.
    2017-11-21T14:17:09.978Z [ 5532] ERROR WinMain SophosUpdate has failed: Failed to initialize COM.