Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 7 replies
  • Subscribers 1 subscriber
  • Views 6725 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,

    the Update logs shows just an idle check (i.e. the client found its cache equal to the CID and therefore no action was necessary), likewise the snippet from the ALUpdate log. Furthermore the Router log shows that it has informed SEC of some EM-EntityEvent (obviously the update on 10/7/2013 12:19:41 PM) but since then only sent the EM-GetStatus-Replies.

    shows as if they are out-of-date

    what is as if? Do you mean they display Not since ... in the Up to date column?

    computer details of endpoint CS1234 shows that the last successful update is 10/7/2013 12:19:41 PM

    This seems to be correct as far as the logs tell.

    First I thought you see Unknown in the Up to date column - but then there should have been an actual update on the client. This usually occurs when SUM has many CIDs to write and the clients update from one of the already deployed CIDs but before SUM has deployed them all. But that's just an aside. BTW: I see S330 as subscription tag - how come?

    Please could you perhaps describe the out-of-date in detail or provide a screenshot? And is your setup straight forward - i.e. only one SUM - updating from Sophos - on the management server, all CIDs (how many?) local on the server, Recommended subscription(s)?

    Christian

    :44037
Reply
  • 0

    Hello Cherze,

    the Update logs shows just an idle check (i.e. the client found its cache equal to the CID and therefore no action was necessary), likewise the snippet from the ALUpdate log. Furthermore the Router log shows that it has informed SEC of some EM-EntityEvent (obviously the update on 10/7/2013 12:19:41 PM) but since then only sent the EM-GetStatus-Replies.

    shows as if they are out-of-date

    what is as if? Do you mean they display Not since ... in the Up to date column?

    computer details of endpoint CS1234 shows that the last successful update is 10/7/2013 12:19:41 PM

    This seems to be correct as far as the logs tell.

    First I thought you see Unknown in the Up to date column - but then there should have been an actual update on the client. This usually occurs when SUM has many CIDs to write and the clients update from one of the already deployed CIDs but before SUM has deployed them all. But that's just an aside. BTW: I see S330 as subscription tag - how come?

    Please could you perhaps describe the out-of-date in detail or provide a screenshot? And is your setup straight forward - i.e. only one SUM - updating from Sophos - on the management server, all CIDs (how many?) local on the server, Recommended subscription(s)?

    Christian

    :44037
Children
No Data
Cookie Information Banner