Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 7 replies
  • Subscribers 1 subscriber
  • Views 6722 views
  • Users 0 members are here
Options
Suggested
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

Endpoints are out-of-date in SEC but are up-to-date

Cherze

Hello,

We have a Sophos Enterprise Console (SEC) v.5.2 on a Windows server 2003. The DB is a MS SQL 2008 on a Windows server 2008 R2 Standard. All the endpoints are at version 9.7.

I have been having a problem for a will with SEC. Once in a will, 40% to 60% of the endpoints shows as if they are out-of-date. As for an example, the computer details of endpoint CS1234 shows that the last successful update is 10/7/2013 12:19:41 PM.  In its alc.log, I see 7 other successful updates since that date. Here is the latest one:

Time: 10/8/2013 9:19:42

Message: AutoUpdate finished

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Installation of Sophos AutoUpdate skipped

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Installation of SAVXP skipped

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Installation of RMSNT skipped

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Downloading phase completed

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Product cache update from primary server successfully finished

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:41

Message: Downloading product Sophos AutoUpdate from server \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:40

Message: Product cache update from primary server successfully finished

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:40

Message: Downloading product SAVXP from server \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:39

Message: Product cache update from primary server successfully finished

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:39

Message: Downloading product RMSNT from server \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\

Module: CIDUpdate

Process ID: 1068

Thread ID: 4524

Time: 10/8/2013 9:19:39

Message: ***************          Sophos AutoUpdate started          ***************

Module: ALUpdate

Process ID: 1068

Thread ID: 4524

I don't see any error messages. To me, everything seems fine.

I also looked into the ALUpdate****.log file. Here is the latest update in the file:

Trace(2013-Oct-08 09:19:39): ALUpdate started: -ScheduledUpdate  -NoGUI -RootPath "C:\Program Files\Sophos\AutoUpdate"
Trace(2013-Oct-08 09:19:39): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} has been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} is not  available from Sophos.
Trace(2013-Oct-08 09:19:39): Product iProductData.{390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92} is not  the Spam Rules package.
Trace(2013-Oct-08 09:19:39): Product iProductData.{D752FAB9-5883-4b36-8740-61565B6BAD29} has not been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} has been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is  available from Sophos.
Trace(2013-Oct-08 09:19:39): Product iProductData.{E17FE03B-0501-4aaa-BC69-0129D965F311} is not  the Spam Rules package.
Trace(2013-Oct-08 09:19:39): Product subscription is disabled: iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} action value is:0
Trace(2013-Oct-08 09:19:39): Product iProductData.{7998C326-2CA5-4830-B7D2-B792D2460975} has not been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{3B758ED7-87C1-4e89-BDE1-F49DFF1249F6} has not been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} has been added.
Trace(2013-Oct-08 09:19:39): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is  available from Sophos.
Trace(2013-Oct-08 09:19:39): Product iProductData.{B5E7E2A7-3B64-437D-801F-21CC9D67CC6D} is  the Spam Rules package.
Trace(2013-Oct-08 09:19:39): ConfigurationImpl, considering PMSR 2.6: PureMessage not installed, PMSR package will not be updated without a subscription
Trace(2013-Oct-08 09:19:39): Considering subscribed products.
Trace(2013-Oct-08 09:19:39): Considering product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8}
Trace(2013-Oct-08 09:19:39): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} is not already subscribed.
Trace(2013-Oct-08 09:19:39): Product {9BF40A4E-23AE-48be-9974-5A1F261DBEE8} was added to the list.
Trace(2013-Oct-08 09:19:39): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2013-Oct-08 09:19:39): Could not read registry entry containing Sophos address - using hardcoded value.
Trace(2013-Oct-08 09:19:39): GenerateCustomerID: complete
Trace(2013-Oct-08 09:19:39): IPCBase::IPCBase: Connected to shared memory A32951C539924a12B3C8F2FDA5A268E4
Trace(2013-Oct-08 09:19:39): IPCSender::ProcessSend started
Trace(2013-Oct-08 09:19:39): IPCSender::ProcessSend: No messages in queue, starting to wait
Trace(2013-Oct-08 09:19:39): RMSMessageHandler: ALUpdateStart
Trace(2013-Oct-08 09:19:39): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
Trace(2013-Oct-08 09:19:39): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSStartUpdate" />
Trace(2013-Oct-08 09:19:39): IPCSender::ProcessSend: No messages in queue, starting to wait
Trace(2013-Oct-08 09:19:39): ALUpdate(AutoUpdate.Started):
Trace(2013-Oct-08 09:19:39): UpdateCoordinator::UpdateNow: Entering
Trace(2013-Oct-08 09:19:39): PopulateCache: Entering
Trace(2013-Oct-08 09:19:39): UpdateCoordinator::UpdateNow: About to Sync list of products
Trace(2013-Oct-08 09:19:39): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
Trace(2013-Oct-08 09:19:39): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Started:
Trace(2013-Oct-08 09:19:39): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, creating update location
Trace(2013-Oct-08 09:19:39): Calling package_source_init
Trace(2013-Oct-08 09:19:39): TrySyncProduct, Calling BeginSync
Trace(2013-Oct-08 09:19:39): Logging on network access user
Trace(2013-Oct-08 09:19:39): Attempting to make a connection to remote machine \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\
Trace(2013-Oct-08 09:19:39): Connection to remote machine \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\ successful
Trace(2013-Oct-08 09:19:39): ParseCustomerIDFile: completed: 0
Trace(2013-Oct-08 09:19:39): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Calling SyncProduct with {390DCDC2-10A9-4ef3-B8D8-0CA7F0E7EB92}
Trace(2013-Oct-08 09:19:39): CIDUpdateLocation::SyncProduct - Updating Product: RMSNT
Trace(2013-Oct-08 09:19:39): CIDUpdate(SyncProduct.Start): RMSNT, \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\
Trace(2013-Oct-08 09:19:39): Checksum found in master.upd matches cached cidsync.upd : 31251f3f. Skipping download
Trace(2013-Oct-08 09:19:39): CIDUpdate(PrimarySuccess):
Trace(2013-Oct-08 09:19:40): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, SyncProduct returned - 1
Trace(2013-Oct-08 09:19:40): TrySyncProduct<class AutoUpdate::CIDUpdateLocation>, Ended - 1
Trace(2013-Oct-08 09:19:40): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
Trace(2013-Oct-08 09:19:40): CIDUpdateLocation::SyncProduct - Updating Product: SAVXP
Trace(2013-Oct-08 09:19:40): CIDUpdate(SyncProduct.Start): SAVXP, \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\
Trace(2013-Oct-08 09:19:40): Checksum found in master.upd matches cached cidsync.upd : 360bb829. Skipping download
Trace(2013-Oct-08 09:19:40): CIDUpdate(PrimarySuccess):
Trace(2013-Oct-08 09:19:41): UpdateLocationFacade::SyncProduct: Last Update Mechanism = CID
Trace(2013-Oct-08 09:19:41): CIDUpdateLocation::SyncProduct - Updating Product: Sophos AutoUpdate
Trace(2013-Oct-08 09:19:41): CIDUpdate(SyncProduct.Start): Sophos AutoUpdate, \\SophosServer\SophosUpdate\CIDs\S330\SAVSCFXP\
Trace(2013-Oct-08 09:19:41): Checksum found in master.upd matches cached cidsync.upd : 4e8b8359. Skipping download
Trace(2013-Oct-08 09:19:41): CIDUpdate(PrimarySuccess):
Trace(2013-Oct-08 09:19:41): ALUpdate(DownloadEnded):
Trace(2013-Oct-08 09:19:41): UpdateCoordinator::UpdateNow: About to Action list of products
Trace(2013-Oct-08 09:19:41): ALUpdate(Action.Skipped): RMSNT
Trace(2013-Oct-08 09:19:41): ALUpdate(Action.Skipped): SAVXP
Trace(2013-Oct-08 09:19:41): ALUpdate(Action.Skipped): Sophos AutoUpdate
Trace(2013-Oct-08 09:19:42): RMSMessageHandler: ALUpdateEnd
Trace(2013-Oct-08 09:19:42): Sending message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate" />
Trace(2013-Oct-08 09:19:42): IPCSender::Write: Writing message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate" />
Trace(2013-Oct-08 09:19:42): IPCSender::ProcessSend: Send message: <?xml version="1.0" encoding="utf-8" ?><Config type="RMSEndUpdate" />
Trace(2013-Oct-08 09:19:42): IPCSender::ProcessSend: No messages in queue, starting to wait
Trace(2013-Oct-08 09:19:43): IPCSender::ProcessSend exiting

Is there something in that log that I don't see which could explain why SEC is not accurate?

On the server side, I don't see anything stock into the Envelopes folder related to that endpoint. In the Router-****.log file, the latest entry regarding that endpoint is the following:

07.10.2013 21:20:08 0A2C I Routing to EM: id=00535DC8, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
07.10.2013 21:20:08 0A1C I Sent message (id=00535DC8) to EM

On the client side, in the Router-****.log file, I see weird things after 10/7/2013 12:19:41 PM:

07.10.2013 12:19:41 0AA0 I Routing to parent: id=0052DF1D, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-EntityEvent
07.10.2013 12:19:41 0A98 I Sent message (id=0052DF1D) to Router$SophosServer
07.10.2013 13:14:35 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 14:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 15:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 15:20:14 0AA0 I Routing to parent: id=0053096E, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
07.10.2013 15:20:14 0A9C I Sent message (id=0053096E) to Router$SophosServer
07.10.2013 16:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 17:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 17:22:21 0AA0 I Routing to parent: id=0053260D, origin=Router$CD1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
07.10.2013 17:22:21 0A94 I Sent message (id=0053260D) to Router$SophosServer
07.10.2013 18:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 19:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 20:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 21:14:36 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 21:20:08 0AA0 I Routing to parent: id=00535DC8, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
07.10.2013 21:20:08 0A98 I Sent message (id=00535DC8) to Router$SophosServer
07.10.2013 22:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
07.10.2013 23:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 00:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 00:20:09 0AA0 I Routing to parent: id=005387F9, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
08.10.2013 00:20:09 0A9C I Sent message (id=005387F9) to Router$SophosServer
08.10.2013 01:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 02:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 03:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 03:20:09 0AA0 I Routing to parent: id=0053B229, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
08.10.2013 03:20:09 0A94 I Sent message (id=0053B229) to Router$SophosServer
08.10.2013 04:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 05:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 06:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 06:20:09 0AA0 I Routing to parent: id=0053DC59, origin=Router$CS1234:720111.Agent, dest=EM, type=EM-GetStatus-Reply
08.10.2013 06:20:09 0A98 I Sent message (id=0053DC59) to Router$SophosServer
08.10.2013 07:14:37 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 08:14:38 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 09:14:38 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
08.10.2013 10:14:38 0A54 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360

I have been having this problem for the last 2 months. I rebooted the SophosServer and the SQLserver on September 25, which helped for 2 weeks. But now the problem is coming back.

At first, I was restarting the Sophos Message Router service on the endpoints, which seemed to help for a day or 2. I don't think that this workaround is viable considering the amount of endpoints. Can someone help me with that issue?

Thank you for your help!

Cherze

:43981


This thread was automatically locked due to age.
Parents
  • 0

    Hello Cherze,

    UpToDateLatencyMins

    setting it back to the default 60 minutes should actually have the converse effect, i.e. more clients should be flagged as being out of date. To rephrase, SEC waits UpToDateLatency in minutes before considering a client as out of date. So the problem must be something else.

    Envelopes folder

    RMS is obviously passing the messages to the management service, so it is not a communications issue. 

    our SUM was not up to date ... 3 different shares

    This could be caused by it constantly failing to update the off site share, e.g. because of network issues or because the share is corrupt (don't worry, it is not permanently damaged - normally deleting its contents will cause it to be successfully rebuilt) or one of the other shares is corrupt. Is SophosServer your management server or is this just a pseudonym for the update location. I see that at least one share is off-site-remote, one is likely the default on the server, what about the third - is it "LAN-remote" (i.e. SUM is writing to a share hosted by another server on the LAN)? It might not be the off-site share which is causing problems though - if you view the update manager details the status of the shares and potential errors are listed under Software subscription status (if possible please provide a screenshot or copy/paste the text here).

    If the off-site link is significantly slower than LAN speed using a secondary SUM is probably expedient. Deployment to a local share likely performs better than writing of a remote share (especially over a slow or  less reliable link). It's not rocket science to set one up (and you could use different intervals or - for software updates - a schedule to allow for the link's properties).

    Christian

    :44241
Reply
  • 0

    Hello Cherze,

    UpToDateLatencyMins

    setting it back to the default 60 minutes should actually have the converse effect, i.e. more clients should be flagged as being out of date. To rephrase, SEC waits UpToDateLatency in minutes before considering a client as out of date. So the problem must be something else.

    Envelopes folder

    RMS is obviously passing the messages to the management service, so it is not a communications issue. 

    our SUM was not up to date ... 3 different shares

    This could be caused by it constantly failing to update the off site share, e.g. because of network issues or because the share is corrupt (don't worry, it is not permanently damaged - normally deleting its contents will cause it to be successfully rebuilt) or one of the other shares is corrupt. Is SophosServer your management server or is this just a pseudonym for the update location. I see that at least one share is off-site-remote, one is likely the default on the server, what about the third - is it "LAN-remote" (i.e. SUM is writing to a share hosted by another server on the LAN)? It might not be the off-site share which is causing problems though - if you view the update manager details the status of the shares and potential errors are listed under Software subscription status (if possible please provide a screenshot or copy/paste the text here).

    If the off-site link is significantly slower than LAN speed using a secondary SUM is probably expedient. Deployment to a local share likely performs better than writing of a remote share (especially over a slow or  less reliable link). It's not rocket science to set one up (and you could use different intervals or - for software updates - a schedule to allow for the link's properties).

    Christian

    :44241
Children
No Data
Cookie Information Banner