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

Most Clients Shown As 'Disconnected' in SEC 5.5.0

Hi folks,

We are running Sophos Enterprise Console (SEC) 5.5.0 on a Windows 2008 R2 Enterprise (64-bit) Server.

I have recently noticed that more than 50% of our client PCs to which Sophos Endpoint Security & Control has been deployed are shown as 'disconnected' in SEC. I have carried out a ping-sweep of the network and can confirm that most, if not all, of these PCs are actually powered on, connected to the network and working fine.

Only after I restart the Sophos Message Router Service on the client PCs do they then change their status to 'connected' in SEC. I have no wish to carry this task out on several hundred client PCs individually as you can imagine, so I'm hoping someone can possibly shed some light on what may be happening here and suggest a solution to this issue?

Many thanks,

John P



This thread was automatically locked due to age.
Parents
  • I'm sure there will be others offering advice, but from my experience, it's most likely that the Remote Management System (RMS) that cannot communicate on the required ports.  You can try with the telnet command from the server to the endpoint and vice versa on the required ports.

    You may like to watch the video below on setting up a GPO to allow the required ports (this means you don't have to go round to each computer).  Watch from the 9 minute mark...

    There is also the deployment guide which mentions the ports. http://www.sophos.com/deployment - click the 'Allowing computers to report' link on the right-hand rail.

     - - - - - - - - - - - -

    Communities Moderator, SOPHOS
    Knowledge Base  |  @SophosSupport  |  Video tutorials
    Remember to like a post.  If a post (on a question thread) solves your question use the 'This helped me' link.

  • Hi guys,

    Thank you for your prompt and helpful replies.

    Christian, I have to admit that I may be a bit lax in checking my SEC installation. Unfortunately, my duties dictate that I cannot spend as much time as I'd like (or indeed, need) to monitor our SEC installation. Wearing too many hats at times methinks!!

    19.09.2017 08:28:19 0B28 I SOF: C:\ProgramData/Sophos/Remote Management System/3/Router/Logs/Router-20170919-072819.log
    19.09.2017 08:28:19 0B28 I Sophos Messaging Router 4.1.1.127 starting...
    19.09.2017 08:28:19 0B28 I Setting ACE_FD_SETSIZE to 138
    19.09.2017 08:28:19 0B28 I Initializing CORBA...
    19.09.2017 08:28:19 0B28 I Connection cache limit is 10
    19.09.2017 08:28:20 0B28 I Router::ConfigureSslContext: keeping legacy compatibility of TLS 1 and TLS 1.1.
    19.09.2017 08:28:20 0B28 I Creating ORB runner with 4 threads
    19.09.2017 08:28:20 0B28 I Compliant certificate hashing algorithm.
    19.09.2017 08:28:20 0B28 I This computer is part of the domain SECRAT
    19.09.2017 08:28:20 0B28 I This router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a0000000010102000a0000003132372e302e302e310001204100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f7574657200000003000000000000000800000001000e01004f4154010000001800000001000e01010001000100000001000105090101000000000014000000080000000100a60086000220
    19.09.2017 08:28:20 0B28 E Localhost address (e.g. 127/8) found in the IOR
    19.09.2017 08:28:20 0B28 E This router's IOR is invalid
    19.09.2017 08:28:20 0B28 I This computer is part of the domain ****
    19.09.2017 08:28:20 0B28 I Reading router table file
    19.09.2017 08:28:20 0B28 I Host name: DNIA16807
    19.09.2017 08:28:20 0B28 I Local IP addresses: 10.63.14.118 
    19.09.2017 08:28:20 0B28 I Resolved name: DNIA16807.****.****.****
    19.09.2017 08:28:20 0B28 I Resolved alias/es: 
    19.09.2017 08:28:20 0B28 I Resolved IP addresses: 127.0.0.1 
    19.09.2017 08:28:20 0B28 I Resolved reverse names/aliases: DNIA16807.****.****.**** 
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01AE532F, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01AE8D1F, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01AFA2D6, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01AFDE91, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0B28 I Waiting for messages...
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B0F5D5, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B13019, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B245FF, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B28197, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B63A35, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B67608, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B78F73, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B7C79E, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B8DE7B, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01B91916, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BA3121, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BA6A99, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BB8324, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BBBBFE, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BF7130, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BF7254, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BF726D, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BF9C9C, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BFB08B, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:28:20 0CB8 I Routing to parent: id=01BFC6D0, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 08:28:20 0CCC W Delivery failed(Timeout) for message type EM-GetStatus-Reply, originator Router$DNIA16807:450391.Agent
    19.09.2017 08:28:20 0CCC W Delivery failed(Timeout) for message type EM-GetStatus-Reply, originator Router$DNIA16807:450391.Agent
    19.09.2017 08:28:20 0CCC W Delivery failed(Timeout) for message type EM-GetStatus-Reply, originator Router$DNIA16807:450391.Agent
    19.09.2017 08:28:20 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 3, max number of user ports 15360
    19.09.2017 08:28:20 0CCC W Delivery failed(Timeout) for message type EM-GetStatus-Reply, originator Router$DNIA16807:450391.Agent
    19.09.2017 08:28:22 0C94 I Client::LogonPushPush() successfully called back to client
    19.09.2017 08:28:22 0C94 I Logged on Agent as a client
    19.09.2017 08:28:22 0CB8 I Routing to Agent: id=03C0C716, origin=Router$DNIA16807:450391, dest=Router$DNIA16807:450391.Agent, type=EM-ClientLogon
    19.09.2017 08:28:22 0CAC I Sent message (id=03C0C716) to Agent
    19.09.2017 08:28:22 0CB8 I Received message for this router
    19.09.2017 08:28:22 0CB8 I EM-NotifyClientUpdates originator Router$DNIA16807:450391.Agent
    19.09.2017 08:28:22 0CB8 I Routing to Agent: id=07C0C716, origin=Router$DNIA16807:450391, dest=Router$DNIA16807:450391.Agent, type=EM-NotifyClientUpdates-Reply
    19.09.2017 08:28:22 0CB0 I Sent message (id=07C0C716) to Agent
    19.09.2017 08:28:57 0CB8 I Routing to parent: id=01C0C739, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 08:33:48 0CB8 I Routing to parent: id=01C0C85C, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 08:34:10 0CCC W Delivery failed(Timeout) for message type EM-EntityEvent, originator Router$DNIA16807:450391.Agent
    19.09.2017 08:34:14 0CB8 I Routing to parent: id=01C0C876, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 09:28:20 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 5, max number of user ports 15360
    19.09.2017 10:28:20 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 5, max number of user ports 15360
    19.09.2017 11:28:21 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 5, max number of user ports 15360
    19.09.2017 12:28:21 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 5, max number of user ports 15360
    19.09.2017 12:40:21 0CCC W Delivery failed(Timeout) for message type EM-EntityEvent, originator Router$DNIA16807:450391.Agent
    19.09.2017 12:40:50 0CB8 I Routing to parent: id=01C10242, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:28:21 0B28 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 5, max number of user ports 15360
    
    
    
    19.09.2017 13:36:47 1AA4 I SOF: C:\ProgramData/Sophos/Remote Management System/3/Router/Logs/Router-20170919-123647.log
    19.09.2017 13:36:47 1AA4 I Sophos Messaging Router 4.1.1.127 starting...
    19.09.2017 13:36:47 1AA4 I Setting ACE_FD_SETSIZE to 138
    19.09.2017 13:36:47 1AA4 I Initializing CORBA...
    19.09.2017 13:36:47 1AA4 I Connection cache limit is 10
    19.09.2017 13:36:48 1AA4 I Router::ConfigureSslContext: keeping legacy compatibility of TLS 1 and TLS 1.1.
    19.09.2017 13:36:48 1AA4 I Creating ORB runner with 4 threads
    19.09.2017 13:36:48 1AA4 I Compliant certificate hashing algorithm.
    19.09.2017 13:36:48 1AA4 I This computer is part of the domain ****
    19.09.2017 13:36:48 1AA4 I This router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a4000000010102000d00000031302e36332e31342e313138000001204100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f7574657200000003000000000000000800000001001d01004f4154010000001800000001001d01010001000100000001000105090101000000000014000000080000000100a60086000220
    19.09.2017 13:36:48 1AA4 I Successfully validated this router's IOR
    19.09.2017 13:36:48 1AA4 I Reading router table file
    19.09.2017 13:36:48 1AA4 I Host name: DNIA16807
    19.09.2017 13:36:48 1AA4 I Local IP addresses: 10.63.14.118 
    19.09.2017 13:36:48 1AA4 I Resolved name: DNIA16807.****.****.****
    19.09.2017 13:36:48 1AA4 I Resolved alias/es: 
    19.09.2017 13:36:48 1AA4 I Resolved IP addresses: 10.63.14.118 
    19.09.2017 13:36:48 1AA4 I Resolved reverse names/aliases: DNIA16807.****.****.**** 
    19.09.2017 13:36:48 1AA4 I Waiting for messages...
    19.09.2017 13:36:48 1988 I Routing to parent: id=01AFA2D6, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1AA4 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 4, max number of user ports 15360
    19.09.2017 13:36:48 1988 I Routing to parent: id=01AFDE91, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B0F5D5, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B13019, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B245FF, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B28197, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1B2C I Getting parent router IOR from 10.63.20.72:8192
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B63A35, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B67608, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B78F73, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B7C79E, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B8DE7B, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01B91916, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BA3121, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BA6A99, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BB8324, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BBBBFE, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BF7254, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01BFB08B, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01C0C739, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 13:36:48 1988 I Routing to parent: id=01C0C85C, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1988 I Routing to parent: id=01C0C876, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-GetStatus-Reply
    19.09.2017 13:36:48 1988 I Routing to parent: id=01C10242, origin=Router$DNIA16807:450391.Agent, dest=EM, type=EM-EntityEvent
    19.09.2017 13:36:48 1B2C I Received parent router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a4000000010102000c00000031302e36332e32302e3732004fc000004100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f757465720000000300000000000000080000000100b700004f415401000000180000000100b700010001000100000001000105090101000000000014000000080000000100a60086000220
    19.09.2017 13:36:48 1B2C I Successfully validated parent router's IOR
    19.09.2017 13:36:48 1B2C I Accessing parent
    19.09.2017 13:36:48 1B2C I SSL handshake done, local IP address = 10.63.14.118
    19.09.2017 13:36:48 1B2C I Parent is Router$SV-AV-01
    19.09.2017 13:36:48 1B2C I RouterTableEntry::LogonToParentRouter() - logging on as active consumer
    19.09.2017 13:36:48 1B0C I SSL handshake done, local IP address = 10.63.14.118
    19.09.2017 13:36:48 1B2C I RouterTableEntry state (router, logging on): Router$SV-AV-01 is passive consumer, passive supplier
    19.09.2017 13:36:48 1B2C I Logged on to parent router as Router$DNIA16807:450391
    19.09.2017 13:36:48 1B2C I This computer is part of the domain SECRAT
    19.09.2017 13:36:48 1C14 I Sent message (id=01AFA2D6) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01AFDE91) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B0F5D5) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B13019) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B245FF) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B28197) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B63A35) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B67608) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B78F73) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B7C79E) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B8DE7B) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01B91916) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BA3121) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BA6A99) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BB8324) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BBBBFE) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BF7254) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01BFB08B) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01C0C739) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01C0C85C) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01C0C876) to Router$SV-AV-01
    19.09.2017 13:36:48 1C14 I Sent message (id=01C10242) to Router$SV-AV-01
    
    
    

    Anyway, attached (I hope) is a copy of the client message router logs showing the situation before and after the Sophos Message Router service restart.

    Hope this helps.

    Ruckus, many thanks for your input. I will review the material you suggested and will keep you posted of any developments.

    Best regards,

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Hello JohnP,

    No offence intended Ruckus, but I remain to be convinced that the proposed answer is the correct one.  This would only be true if more than 50% of JohnP's computers were incorrectly configured in the first place and that the firewall of these computers were blocking TCP ports 8192/4.  Based on our recent experience I think it is fair to assume this is unlikely to be the case, but easily checked out by reviewing this thread: https://community.sophos.com/products/endpoint-security-control/f/sophos-enterprise-console/79261/connection

    We are also running Enterprise console v5.5.0, investigating the same problem and have logged a call with Sophos support who are looking into the issue.  All of our computers are configured correctly which allow them to contact the console.  The console is reporting that some of these computers are disconnected (not the case) and all affected systems are laptops.  Like you we identified the localhost resolved IP address in the remote management system router log and have made Sophos aware of our findings.  When reviewing the logs after restarting the Sophos Message Router service, the resolved IP address is the same as the local IP address and the console reports that the computer is online.  After a reboot your are back to square one, unless that is you change the Sophos Message Router service startup type from Automatic to Automatic (Delayed Start).

    We noticed the issue following the Microsoft September 2017 security update release which we rolled out on Wednesday 13th and wondered and have been looking into whether this was a contributing factor. In the meantime Sophos are analysing SDU logs taken from initially the server and today both the server and an affected workstation.

    Ian.

  • Np Ian! [:)]  JohnP can check and use one of the options on my reply...

     - - - - - - - - - - - -

    Communities Moderator, SOPHOS
    Knowledge Base  |  @SophosSupport  |  Video tutorials
    Remember to like a post.  If a post (on a question thread) solves your question use the 'This helped me' link.

  • Hi Ian,

    Thank you very much for your input, it has proven very useful. We do not have many laptops on our network and the clients affected by this issue are all desktop PCs running Windows 10.

    Is the delayed start of the Sophos Message Router service a temporary workaround to this issue, that is, after a reboot, will SEC report the clients as still being 'connected'?

    I also have a call in with Sophos Support about this and they asked if anything had been changed on our network (no) and they then recommended that I re-protect some PCs which are currently shown as 'disconnected'. I have done this and SEC has restored connectivity to these particular clients. However, I will wait until they are re-booted again to see if this works, not confident though.

    Will keep you all posted.

     

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Hello Ian,

    kudos for this contribution.
    May I ask which Windows version(s)? You say that the affected ones are definitely all laptops (and all of them had the security updates) but not all laptops are affected? Changing the startup type seems to be a viable workaround. Naturally I can't say what the reason for the Router's current behaviour is.

    Can't say what the sequence of actions is (a verbose log might give some insight but you can't change how it works anyway). It looks like a (LAN) connection appears to be available, the Router enumerates the available addresses, and - even though it finds only localhost and flags it as error - attempts to use it to initiate a connection to its parent but subsequently get just a timeout (sorry for the winded sentence). It seems to be in the state to just retry the connection instead of either checking for changes or simply reinitializing.
    Apparently the interface is already fully up at the time of the Delayed Start. Automatic (Delayed Start) is two minutes after the start of the last Automatic service, shouldn't have an effect.

    Christian

  • Hi JohnP,

    Firstly...  fair point ruckus and my apologies; my first post and I overlooked your feedback options. 

    We have been mooching around this issue since yesterday.  If you re-protect a PC it will appear to be connected until it reboots, at which time the console remains waiting for the reboot request to be acknowledged with the computer being reported as disconnected even though this is not the case. On the workstation Sophos updates as normal.  This is not reflected in the console.  I assume the updates are being downloaded from the application server hosting enterprise console although it may well be the secondary location we have configured in updating, in our case Sophos.

    On a separate affected workstation, having changed the Sophos Message Router service startup type from Automatic to Automatic (Delayed Start), after a reboot the computer is reported as being disconnected until the delayed service starts (after 2 minutes or so) when the console changes the status to connected.  The computer maintains contact with the console.  I'm going to check this particular workstation tomorrow, hopefully to verify that the Sophos AutoUpdate status reports that the computer has been updated successfully.

    We utilise a deployment tool which also detects the online status of clients.  This is working as usual.  Computers known to be online being reported as such, whereas the Sophos console is reporting some of these computers as being disconnected even though they are known to be online.

    Like you, nothing has changed on our network other than the Microsoft September 2017 security update release we rolled out on Wednesday 13th.

    We await Sophos to get back to us following analysis of the logs we emailed them this morning.

    Ian.

  • Hi Ian,

    Many thanks for the update. I anticipate that sometime in the near future Sophos Support will ask me to ensure that the client PC can connect to the SEC Server on ports 8192 & 8194.

    Rather than spend the next few days running around like a headless chicken, our resident Powershell expert has given me a script which will check connectivity to these two ports from the 'disconnected' client PC, all from the comfort of my own desk!!

    PS C:\windows\system32> icm -ComputerName clientpcname -ScriptBlock {"8192","8194" | % {Test-NetConnection -ComputerName secservername -Port $_}}

    It takes a few seconds to run, but I thought it quite clever. Output looks like:

    ComputerName           : secservername
    RemoteAddress          : 10.63.20.72
    RemotePort             : 8192
    InterfaceAlias         : Ethernet
    SourceAddress          : 10.63.26.111
    PingSucceeded          : True
    PingReplyDetails (RTT) :
    TcpTestSucceeded       : True
    PSComputerName         : clientpcname

    ComputerName           : secservername
    RemoteAddress          : 10.63.20.72
    RemotePort             : 8194
    InterfaceAlias         : Ethernet
    SourceAddress          : 10.63.26.111
    PingSucceeded          : True
    PingReplyDetails (RTT) :
    TcpTestSucceeded       : True
    PSComputerName         : clientpcname

    This PC is shown as 'disconnected' from SEC. However, the output above leads me to think that it can communicate with the SEC Server on the necessary ports.

    Keep on plugging!!

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Hello Christian,

    Windows 10 version 1703 (OS build 15063.608) and Windows 10 version 1607 (OS build 14393.1715).

    The affected workstations are all laptops, the opposite of JohnP who advises in his case clients affected by this issue are all desktop PCs running Windows 10.

    Not all laptops are affected. All laptops are patched up to date.

    Windows 10 version 1703 (OS build 15063.608): Update for Microsoft Windows (KB4022405) and Security Update for Microsoft Windows (KB4038788).

    Windows 10 version 1607 (OS build 14393.1715): Update for Microsoft Windows (KB4035631), Security Update for Microsoft Windows (KB4033637) and Security Update for Microsoft Windows (KB4038782).

    We have noted that if you disconnect an affected laptop from the network (unplug the Ethernet connector) and reconnect, a short while later the console report the device as being online.  All good until you reboot.

    Ian.

  • Hello John P and Ian,

    it can communicate
    or it could. It's "just" that RMS "can't get out". Apparently this is reproducibly the case when it initializes after a reboot. It works on a subsequent restart or a change on the adapter (guess disable/enable has the same effect as unplug/plug) as the adapter is in the expected/necessary state.

    Updating or other functions are not affected, but there's no communication with the management server (no endpoint status, you can't apply policies, and so on).   

    Christian

  • Hi all,

    On a further note I have discovered when I run a netstat command on a PC that is shown as 'connected' in SEC, I get the following output:

    C:\windows\system32>netstat -ano | findstr :8194
      TCP    0.0.0.0:8194                 0.0.0.0:0                       LISTENING         7644
      TCP    10.63.26.110:8194       10.63.26.110:59106     ESTABLISHED     7644
      TCP    10.63.26.110:59106     10.63.26.110:8194       ESTABLISHED     2348
      TCP    10.63.26.110:60814     10.63.20.72:8194         ESTABLISHED     7644

    C:\windows\system32>netstat -ano | findstr :8192
      TCP    0.0.0.0:8192                  0.0.0.0:0                      LISTENING       7644

    Looks pretty OK. Client PC IP address is 10.63.26.110, SEC Server IP Address is 10.63.20.72. However, on a PC shown as 'disconnected' the following output is shown:

    C:\windows\system32>netstat -ano | findstr :8194
    TCP 0.0.0.0:8194                      0.0.0.0:0                       LISTENING 2496
    TCP 127.0.0.1:8194                 127.0.0.1:49420            ESTABLISHED 2496
    TCP 127.0.0.1:49420               127.0.0.1:8194              ESTABLISHED 2248

    C:\windows\system32>netstat -ano | findstr :8192
    TCP 0.0.0.0:8192                     0.0.0.0:0                        LISTENING 2496

    Like Christian, I have no idea why the 'disconnected' client is resolving to a loopback address.

    I'll pass these findings on to Sophos Support and let you know how things progress.

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Another day...

    Early on Wednesday morning we supplied Sophos with SDU logs taken from both the server and an affected workstation. We were a little anxious at the time they were taking to respond and did so only after a prompt late yesterday afternoon.  It transpires that Sophos are aware of this issue also affecting JohnP and commented that although information was limited in his case, after reviewing this thread suggested that the problem was likely the same.  I would have thought they were identical to be honest.

    Sophos suggested that our logs and those of JohnP indicated that the affected workstation were attempting to contact the console using TLS 1.0.  I did not believe this was the case as we deploy from one of two images and as a result our workstations are to all intents and purposes identical.  The suggestion also failed to address why only a relatively small percentage of these workstation are affected and that these were working last week.  We installed Wireshark on the server and supplied Sophos with Wireshark logs after following the instruction in this article: https://community.sophos.com/kb/en-us/126422  Adding 8194 to the SSL box in HTTP and applying the filter ssl.handshake.version == 0x0301 && tcp.port == 8194 confirmed no computers were attempting to connect to the console using TLS 1.0

    We are advised that the call has been passed to a level 2 engineer and a Sophos's senior engineer.

    Ian.

Reply
  • Another day...

    Early on Wednesday morning we supplied Sophos with SDU logs taken from both the server and an affected workstation. We were a little anxious at the time they were taking to respond and did so only after a prompt late yesterday afternoon.  It transpires that Sophos are aware of this issue also affecting JohnP and commented that although information was limited in his case, after reviewing this thread suggested that the problem was likely the same.  I would have thought they were identical to be honest.

    Sophos suggested that our logs and those of JohnP indicated that the affected workstation were attempting to contact the console using TLS 1.0.  I did not believe this was the case as we deploy from one of two images and as a result our workstations are to all intents and purposes identical.  The suggestion also failed to address why only a relatively small percentage of these workstation are affected and that these were working last week.  We installed Wireshark on the server and supplied Sophos with Wireshark logs after following the instruction in this article: https://community.sophos.com/kb/en-us/126422  Adding 8194 to the SSL box in HTTP and applying the filter ssl.handshake.version == 0x0301 && tcp.port == 8194 confirmed no computers were attempting to connect to the console using TLS 1.0

    We are advised that the call has been passed to a level 2 engineer and a Sophos's senior engineer.

    Ian.

Children
  • Would you provide the logs of the router with loglevel 2 (trace logging enabled)?

    It is detailed here: https://community.sophos.com/kb/en-us/30496 but essentially create a new DWORD value under:

    HKEY_LOCAL_MACHINE\software\WOW6432Node\SOPHOS\messaging system\router

    called LogLevel and set the value to 2.

    If you restart the computer, next time it starts, the router will create a router log with level 2 logging.

    I assume it still has the important error lines:
    E Localhost address (e.g. 127/8) found in the IOR
    E This router's IOR is invalid

    if you leave it maybe a minute or 2, then I assume as before no change, then restart the router, in this case it works?

    Each start of the router process will create a new log.  Could you make available the last 2 logs, i.e. the failure at system startup and then success following the restart of the router.

    Regards,

    Jak

     

  • Hello Jak,

    Following your instructions these logs were taken from a Latitude E7470 laptop with a clean install of Windows 10 and updated through Windows update.  The laptop has been joined to our domain and the user account is a member of the local Administrators group. Winver reports the OS as Version 1607 |(OS Build 14391.1715).  As you can see, the logs report that the routers IOR is invalid until the Sophos Message Router service is restarted upon which the routers IOR is successfully validated. 

    Log following reboot:

    Extract
    25.09.2017 08:56:49 0D88 T MessageRouter::validateIOR called
    25.09.2017 08:56:49 0D88 T Endpoint found: 127.0.0.1:8193
    25.09.2017 08:56:49 0D88 E Localhost address (e.g. 127/8) found in the IOR
    25.09.2017 08:56:49 0D88 E This router's IOR is invalid
    Full log below
    _______________________________________________________________________________________________________________________

    25.09.2017 08:56:48 0D88 I SOF: C:\ProgramData/Sophos/Remote Management System/3/Router/Logs/Router-20170925-075648.log
    25.09.2017 08:56:48 0D88 I Sophos Messaging Router 4.1.1.127 starting...
    25.09.2017 08:56:48 0D88 I Setting ACE_FD_SETSIZE to 138
    25.09.2017 08:56:48 0D88 I Initializing CORBA...
    25.09.2017 08:56:48 0D88 I Connection cache limit is 10
    25.09.2017 08:56:49 0D88 D New context options = 1000004
    25.09.2017 08:56:49 0D88 I Router::ConfigureSslContext: keeping legacy compatibility of TLS 1 and TLS 1.1.
    25.09.2017 08:56:49 0D88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:56:49 0D88 T Added host network address:172.30.20.79:0
    25.09.2017 08:56:49 0D88 T Added host network address:127.0.0.1:0
    25.09.2017 08:56:49 0D88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:56:49 0D88 D Creating ORB...
    25.09.2017 08:56:49 0D88 I Creating ORB runner with 4 threads
    25.09.2017 08:56:49 0F60 D RunORB thread started
    25.09.2017 08:56:49 0F24 D RunORB thread started
    25.09.2017 08:56:49 0FBC D RunORB thread started
    25.09.2017 08:56:49 0FB4 D RunORB thread started
    25.09.2017 08:56:49 0D88 I Compliant certificate hashing algorithm.
    25.09.2017 08:56:49 0D88 D Not requesting a new certificate.
    25.09.2017 08:56:49 0D88 D Resolving the root object adapter...
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::StatusReporter::WriteReport
    25.09.2017 08:56:49 0D88 I This computer is part of the domain PJL
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::DNSSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::DNSSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::StatusReporter::WriteReport
    25.09.2017 08:56:49 0D88 D Creating object adapters...
    25.09.2017 08:56:49 0D88 D Creating MessageRouter CORBA object...
    25.09.2017 08:56:49 0D88 I This router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a0000000010102000a0000003132372e302e302e310001204100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f757465720000000300000000000000080000000100e001004f415401000000180000000100e001010001000100000001000105090101000000000014000000080000000100a60086000220
    25.09.2017 08:56:49 0D88 T MessageRouter::validateIOR called
    25.09.2017 08:56:49 0D88 T Endpoint found: 127.0.0.1:8193
    25.09.2017 08:56:49 0D88 E Localhost address (e.g. 127/8) found in the IOR
    25.09.2017 08:56:49 0D88 E This router's IOR is invalid
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 08:56:49 0D88 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 08:56:49 0D88 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 08:56:49 0D88 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 08:56:49 0D88 T Outgoing       : problem 1, changed 1, already reported 0
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::OutgoingSection::LogNow
    25.09.2017 08:56:49 0D88 T >>> void __thiscall System::EventLogger::LogEvent(unsigned long,unsigned short,const char *,const char *,const char *,const char *,const char *,const char *,const char *,const char *,const char *) const
    25.09.2017 08:56:49 0D88 T >>> void __thiscall System::EventLogger::LogEvent(unsigned long,unsigned short,unsigned short,const char *[]) const
    25.09.2017 08:56:49 0D88 T <<< void __thiscall System::EventLogger::LogEvent(unsigned long,unsigned short,unsigned short,const char *[]) const
    25.09.2017 08:56:49 0D88 T <<< void __thiscall System::EventLogger::LogEvent(unsigned long,unsigned short,const char *,const char *,const char *,const char *,const char *,const char *,const char *,const char *,const char *) const
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::OutgoingSection::LogNow
    25.09.2017 08:56:49 0D88 D class StatusReporting::OutgoingSection changed
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::StatusReporter::WriteReport
    25.09.2017 08:56:49 0D88 I This computer is part of the domain PJL
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::DNSSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::DNSSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T >>> StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::StatusReporter::WriteReport
    25.09.2017 08:56:49 0D88 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 08:56:49 0D88 D Setting NotificationThresholdInitialRetrySecs to 3600
    25.09.2017 08:56:49 0D88 D Setting NotificationThresholdMaxRetrySecs to 172800
    25.09.2017 08:56:49 0D88 I Reading router table file
    25.09.2017 08:56:49 0D88 D Loading envelopes from persistent storage...
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000004.msg" for [id=01C54536, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C54536
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000b.msg" for [id=01C7E837, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C7E837
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000c.msg" for [id=01C8416C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C8416C
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000d.msg" for [id=01C8830C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C8830C
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000011.msg" for [id=01C8B165, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C8B165
    25.09.2017 08:56:49 0D88 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000012.msg" for [id=01C8B27C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 08:56:49 0D88 T Envelope::Shrink
    25.09.2017 08:56:49 0D88 D Shrunk Envelope, id=01C8B27C
    25.09.2017 08:56:49 0D88 D Activating CORBA objects...
    25.09.2017 08:56:49 0D88 I Host name: scopat-win10
    25.09.2017 08:56:49 0D88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:56:49 0D88 T Added host network address:172.30.20.79:0
    25.09.2017 08:56:49 0D88 T Added host network address:127.0.0.1:0
    25.09.2017 08:56:49 0D88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:56:49 0D88 I Local IP addresses: 172.30.20.79 
    25.09.2017 08:56:49 0D88 I Resolved name: scopat-win10.pjl.local
    25.09.2017 08:56:49 0D88 I Resolved alias/es: 
    25.09.2017 08:56:49 0D88 I Resolved IP addresses: 127.0.0.1 
    25.09.2017 08:56:49 0D88 I Resolved reverse names/aliases: scopat-win10.pjl.local 
    25.09.2017 08:56:49 0D88 T Router::doStartRouting() called
    25.09.2017 08:56:49 0D88 T Total time for retrying ACE socket connection 300
    25.09.2017 08:56:49 0D88 T Number of retries when retrying ACE socket connection 100
    25.09.2017 08:56:49 0D88 T Pause between retries when retrying ACE socket connection 2000
    25.09.2017 08:56:49 0D88 T Pause variation percentage range 0
    25.09.2017 08:56:49 0D88 D Router will not restart when it detects an EM or parent sender thread has failed to send 5000 messages.
    25.09.2017 08:56:49 0074 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 0D88 D Initialising router with 0 notification threshold worker threads
    25.09.2017 08:56:49 0EC8 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 0D38 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 1004 T +++ class MessageRouter::RouterThread derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 0D88 I Waiting for messages...
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C54536, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 08:56:49 0D88 D Reducing Size
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C7E837, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 08:56:49 0D88 D RouterSystemCheck: percentageThreshold 85, minimumPortNumToCount 1024, checkIntervalSecs 3600, reportIntervalSecs 86400
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C8416C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C8830C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 08:56:49 0D88 T RouterSystemCheck::getMaxUserPort()
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C8B165, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 08:56:49 0D88 D RouterSystemCheck::getMaxUserPort(), no MaxUserPort value in Registry
    25.09.2017 08:56:49 0D88 D RouterSystemCheck::getMaxUserPort(), value (0) is too low, assuming 16384
    25.09.2017 08:56:49 0D88 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 4, max number of user ports 15360
    25.09.2017 08:56:49 0D88 T CertificateRegenerationChecker::IsItTimeToRefreshCertificate(): key size and hashing algorithm are valid.
    25.09.2017 08:56:49 1004 I Routing to parent: id=01C8B27C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 08:56:49 100C T +++ class MessageRouter::TimeoutThread derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 1014 T +++ class MessageRouter::HostIPAddressMonitor<class ACEHelpers::IPAddressSet> derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 1014 T HostIPAddressMonitor::Process started
    25.09.2017 08:56:49 100C T TimeoutThread::Process() checking table
    25.09.2017 08:56:49 1010 T +++ class MessageRouter::IOR_Sender derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 100C D TimeoutThread::CheckEntry() adding entry: 
    25.09.2017 08:56:49 1008 T +++ class MessageRouter::GetterThread derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 1008 T GetterThread::Process() checking table
    25.09.2017 08:56:49 1018 T +++ class MessageRouter::TimeoutWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 101C T +++ class MessageRouter::GetterWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:49 1020 T +++ class MessageRouter::GetterWorker derived from BasicThreadHelper: starting.
    25.09.2017 08:56:51 0FB4 T MessageRouter::GetClient() called
    25.09.2017 08:56:51 0F60 T Client::Register() called
    25.09.2017 08:56:51 0FB4 T Client::LogonPushPush() called
    25.09.2017 08:56:51 0FB4 I Client::LogonPushPush() successfully called back to client
    25.09.2017 08:56:51 0FB4 D Created "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000013.msg" for [id=03C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-ClientLogon]
    25.09.2017 08:56:51 0FB4 T Envelope::Shrink
    25.09.2017 08:56:51 0FB4 D Shrunk Envelope, id=03C8B6C3
    25.09.2017 08:56:51 0FB4 I Logged on Agent as a client
    25.09.2017 08:56:51 1004 I Routing to Agent: id=03C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-ClientLogon
    25.09.2017 08:56:51 0EC8 T Envelope::GetOriginatorCert
    25.09.2017 08:56:51 0EC8 T Envelope::Expand
    25.09.2017 08:56:51 0FBC T ClientMessageConsumer::Heartbeat() called
    25.09.2017 08:56:51 0EC8 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000013.msg" for [id=03C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-ClientLogon]
    25.09.2017 08:56:51 0EC8 T Envelope::GetData
    25.09.2017 08:56:51 0EC8 T Envelope::Expand
    25.09.2017 08:56:51 0EC8 T Envelope::GetOriginatorCert
    25.09.2017 08:56:51 0EC8 T Envelope::Expand
    25.09.2017 08:56:51 0EC8 D Expanded Envelope, id=03C8B6C3
    25.09.2017 08:56:51 0EC8 T Envelope::GetData
    25.09.2017 08:56:51 0EC8 T Envelope::Expand
    25.09.2017 08:56:51 0EC8 T Sending message (id=03C8B6C3) to Agent
    25.09.2017 08:56:51 0EC8 I Sent message (id=03C8B6C3) to Agent
    25.09.2017 08:56:51 0FBC T ClientMessageConsumer::SendMessage() called
    25.09.2017 08:56:51 0FBC D Created "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000014.msg" for [id=05C8B6C3, origin=Router$scopat-win10:441054.Agent, dest=:, type=EM-NotifyClientUpdates]
    25.09.2017 08:56:51 0FBC T Envelope::Shrink
    25.09.2017 08:56:51 0FBC D Shrunk Envelope, id=05C8B6C3
    25.09.2017 08:56:51 1004 I Received message for this router
    25.09.2017 08:56:51 1004 I EM-NotifyClientUpdates originator Router$scopat-win10:441054.Agent
    25.09.2017 08:56:51 1004 D Created "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000015.msg" for [id=07C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-NotifyClientUpdates-Reply]
    25.09.2017 08:56:51 1004 T Envelope::Shrink
    25.09.2017 08:56:51 1004 D Shrunk Envelope, id=07C8B6C3
    25.09.2017 08:56:51 1004 I Routing to Agent: id=07C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-NotifyClientUpdates-Reply
    25.09.2017 08:56:51 0D38 T Envelope::GetOriginatorCert
    25.09.2017 08:56:51 0D38 T Envelope::Expand
    25.09.2017 08:56:51 0D38 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000015.msg" for [id=07C8B6C3, origin=Router$scopat-win10:441054, dest=Router$scopat-win10:441054.Agent, type=EM-NotifyClientUpdates-Reply]
    25.09.2017 08:56:51 0D38 T Envelope::GetData
    25.09.2017 08:56:51 0D38 T Envelope::Expand
    25.09.2017 08:56:51 0D38 T Envelope::GetOriginatorCert
    25.09.2017 08:56:51 0D38 T Envelope::Expand
    25.09.2017 08:56:51 0D38 D Expanded Envelope, id=07C8B6C3
    25.09.2017 08:56:51 0D38 T Envelope::GetData
    25.09.2017 08:56:51 0D38 T Envelope::Expand
    25.09.2017 08:56:51 0D38 T Sending message (id=07C8B6C3) to Agent
    25.09.2017 08:56:51 0D38 I Sent message (id=07C8B6C3) to Agent
    25.09.2017 08:56:54 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:56:54 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:56:54 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:56:54 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:56:59 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:56:59 1008 T GetterThread::Process() checking table
    25.09.2017 08:56:59 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:56:59 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:56:59 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:04 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:04 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:04 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:04 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:09 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:09 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:09 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:09 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:09 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:11 0FBC T ClientMessageConsumer::SendMessage() called
    25.09.2017 08:57:11 0FBC D Created "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000016.msg" for [id=01C8B6D7, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 08:57:11 0FBC T Envelope::Shrink
    25.09.2017 08:57:11 0FBC D Shrunk Envelope, id=01C8B6D7
    25.09.2017 08:57:11 1004 I Routing to parent: id=01C8B6D7, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 08:57:14 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:14 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:14 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:14 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:19 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:19 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:19 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:19 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:19 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:24 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:24 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:24 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:24 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:29 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:29 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:29 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:29 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:29 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:34 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:34 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:34 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:34 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:39 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:39 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:39 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:39 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:39 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:44 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:44 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:44 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:44 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:49 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:49 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:49 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:49 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:49 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:54 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:54 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:54 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:54 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:57:59 100C T TimeoutThread::Process() checking table
    25.09.2017 08:57:59 100C D TimeoutThread::CheckEntry() adding entry: 
    25.09.2017 08:57:59 1008 T GetterThread::Process() checking table
    25.09.2017 08:57:59 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:57:59 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:57:59 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:57:59 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:04 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:04 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:04 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:04 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:09 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:09 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:09 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:09 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:09 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:14 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:14 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:14 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:14 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:19 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:19 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:19 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:19 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:19 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:24 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:24 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:24 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:24 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:29 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:29 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:29 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:29 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:29 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:34 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:34 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:34 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:34 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:39 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:39 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:39 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:39 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:39 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:44 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:44 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:44 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:44 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:49 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:49 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:49 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:49 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:49 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:54 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:54 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:54 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:54 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:58:59 1008 T GetterThread::Process() checking table
    25.09.2017 08:58:59 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:58:59 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:58:59 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:58:59 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:59:04 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:59:04 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:59:04 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:59:04 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:59:09 100C T TimeoutThread::Process() checking table
    25.09.2017 08:59:09 100C D TimeoutThread::CheckEntry() adding entry: 
    25.09.2017 08:59:09 1008 T GetterThread::Process() checking table
    25.09.2017 08:59:09 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:59:09 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:59:09 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:59:09 1014 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 08:59:14 1014 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 08:59:14 1014 T Added host network address:172.30.20.79:0
    25.09.2017 08:59:14 1014 T Added host network address:127.0.0.1:0
    25.09.2017 08:59:14 1014 T IPAddressSet::InitialiseWithHost() returns
    _______________________________________________________________________________________________________________________
    Log after restarting Sophos Message Router service
    
    Extract
    25.09.2017 09:00:24 0984 T MessageRouter::validateIOR called
    25.09.2017 09:00:24 0984 T Endpoint found: 172.30.20.79:8193
    25.09.2017 09:00:24 0984 I Successfully validated this router's IOR
    Full log below
    _______________________________________________________________________________________________________________________
    25.09.2017 09:00:23 0984 I SOF: C:\ProgramData/Sophos/Remote Management System/3/Router/Logs/Router-20170925-080023.log
    25.09.2017 09:00:23 0984 I Sophos Messaging Router 4.1.1.127 starting...
    25.09.2017 09:00:23 0984 I Setting ACE_FD_SETSIZE to 138
    25.09.2017 09:00:23 0984 I Initializing CORBA...
    25.09.2017 09:00:23 0984 I Connection cache limit is 10
    25.09.2017 09:00:23 0984 D New context options = 1000004
    25.09.2017 09:00:23 0984 I Router::ConfigureSslContext: keeping legacy compatibility of TLS 1 and TLS 1.1.
    25.09.2017 09:00:23 0984 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:23 0984 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:23 0984 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:23 0984 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:23 0984 D Creating ORB...
    25.09.2017 09:00:23 0984 I Creating ORB runner with 4 threads
    25.09.2017 09:00:23 0AA4 D RunORB thread started
    25.09.2017 09:00:23 1664 D RunORB thread started
    25.09.2017 09:00:23 0F08 D RunORB thread started
    25.09.2017 09:00:23 0F48 D RunORB thread started
    25.09.2017 09:00:24 0984 I Compliant certificate hashing algorithm.
    25.09.2017 09:00:24 0984 D Not requesting a new certificate.
    25.09.2017 09:00:24 0984 D Resolving the root object adapter...
    25.09.2017 09:00:24 0984 T >>> StatusReporting::StatusReporter::WriteReport
    25.09.2017 09:00:24 0984 I This computer is part of the domain PJL
    25.09.2017 09:00:24 0984 T >>> StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 09:00:24 0984 T >>> StatusReporting::DNSSection::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::DNSSection::WriteAsXML
    25.09.2017 09:00:24 0984 T >>> StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 09:00:24 0984 T >>> StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 09:00:24 0984 T >>> StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 09:00:24 0984 T <<< StatusReporting::StatusReporter::WriteReport
    25.09.2017 09:00:24 0984 D Creating object adapters...
    25.09.2017 09:00:24 0984 D Creating MessageRouter CORBA object...
    25.09.2017 09:00:24 0984 I This router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a4000000010102000d0000003137322e33302e32302e3739000001204100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f757465720000000300000000000000080000000100dd01004f415401000000180000000100dd01010001000100000001000105090101000000000014000000080000000100a60086000220
    25.09.2017 09:00:24 0984 T MessageRouter::validateIOR called
    25.09.2017 09:00:24 0984 T Endpoint found: 172.30.20.79:8193
    25.09.2017 09:00:24 0984 I Successfully validated this router's IOR
    25.09.2017 09:00:24 0984 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 0984 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0984 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0984 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0984 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0984 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 0984 D Setting NotificationThresholdInitialRetrySecs to 3600
    25.09.2017 09:00:24 0984 D Setting NotificationThresholdMaxRetrySecs to 172800
    25.09.2017 09:00:24 0984 I Reading router table file
    25.09.2017 09:00:24 0984 D Loading envelopes from persistent storage...
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000004.msg" for [id=01C54536, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C54536
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000b.msg" for [id=01C7E837, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C7E837
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000c.msg" for [id=01C8416C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C8416C
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000d.msg" for [id=01C8830C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C8830C
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000011.msg" for [id=01C8B165, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C8B165
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000012.msg" for [id=01C8B27C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C8B27C
    25.09.2017 09:00:24 0984 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000016.msg" for [id=01C8B6D7, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 0984 T Envelope::Shrink
    25.09.2017 09:00:24 0984 D Shrunk Envelope, id=01C8B6D7
    25.09.2017 09:00:24 0984 D Activating CORBA objects...
    25.09.2017 09:00:24 0984 I Host name: scopat-win10
    25.09.2017 09:00:24 0984 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:24 0984 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:24 0984 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:24 0984 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:24 0984 I Local IP addresses: 172.30.20.79 
    25.09.2017 09:00:24 0984 I Resolved name: scopat-win10.pjl.local
    25.09.2017 09:00:24 0984 I Resolved alias/es: 
    25.09.2017 09:00:24 0984 I Resolved IP addresses: 172.30.20.79 
    25.09.2017 09:00:24 0984 I Resolved reverse names/aliases: scopat-win10.pjl.local 
    25.09.2017 09:00:24 0984 T Router::doStartRouting() called
    25.09.2017 09:00:24 0984 T Total time for retrying ACE socket connection 300
    25.09.2017 09:00:24 0984 T Number of retries when retrying ACE socket connection 100
    25.09.2017 09:00:24 0984 T Pause between retries when retrying ACE socket connection 2000
    25.09.2017 09:00:24 0984 T Pause variation percentage range 0
    25.09.2017 09:00:24 0984 D Router will not restart when it detects an EM or parent sender thread has failed to send 5000 messages.
    25.09.2017 09:00:24 19B0 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 1940 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0404 T +++ class MessageRouter::SenderWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0984 D Initialising router with 0 notification threshold worker threads
    25.09.2017 09:00:24 1710 T +++ class MessageRouter::RouterThread derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0984 I Waiting for messages...
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C54536, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 09:00:24 18C0 T +++ class MessageRouter::GetterThread derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0984 D Reducing Size
    25.09.2017 09:00:24 1B80 T +++ class MessageRouter::TimeoutThread derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 18C0 T GetterThread::Process() checking table
    25.09.2017 09:00:24 1B80 T TimeoutThread::Process() checking table
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C7E837, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 09:00:24 1B80 D TimeoutThread::CheckEntry() adding entry: 
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C8416C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 09:00:24 0984 D RouterSystemCheck: percentageThreshold 85, minimumPortNumToCount 1024, checkIntervalSecs 3600, reportIntervalSecs 86400
    25.09.2017 09:00:24 1348 T +++ class MessageRouter::IOR_Sender derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 1A98 T +++ class MessageRouter::ParentLogon derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C8830C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 09:00:24 1A98 I Getting parent router IOR from 172.30.1.46:8192
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C8B165, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 09:00:24 1A98 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 0984 T RouterSystemCheck::getMaxUserPort()
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C8B27C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent
    25.09.2017 09:00:24 1710 I Routing to parent: id=01C8B6D7, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply
    25.09.2017 09:00:24 1B88 T +++ class MessageRouter::HostIPAddressMonitor<class ACEHelpers::IPAddressSet> derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0984 D RouterSystemCheck::getMaxUserPort(), no MaxUserPort value in Registry
    25.09.2017 09:00:24 1B88 T HostIPAddressMonitor::Process started
    25.09.2017 09:00:24 0984 D RouterSystemCheck::getMaxUserPort(), value (0) is too low, assuming 16384
    25.09.2017 09:00:24 1B64 T +++ class MessageRouter::GetterWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 0984 I RouterSystemCheck::onInfoPortsUsed() - number of user ports 6, max number of user ports 15360
    25.09.2017 09:00:24 0984 T CertificateRegenerationChecker::IsItTimeToRefreshCertificate(): key size and hashing algorithm are valid.
    25.09.2017 09:00:24 0948 T +++ class MessageRouter::GetterWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 07DC T +++ class MessageRouter::TimeoutWorker derived from BasicThreadHelper: starting.
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::SetActualParent
    25.09.2017 09:00:24 1A98 D Actual parent is `172.30.1.46`
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::SetActualParent
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 I Received parent router's IOR:
    IOR:010000002600000049444c3a536f70686f734d6573736167696e672f4d657373616765526f757465723a312e300000000100000000000000a4000000010102000c0000003137322e33302e312e343600012000004100000014010f004e5550000000210000000001000000526f6f74504f4100526f7574657250657273697374656e740003000000010000004d657373616765526f757465720000000300000000000000080000000100a800004f415401000000180000000100a800010001000100000001000105090101000000000014000000080000000100a60086000220
    25.09.2017 09:00:24 1A98 T MessageRouter::validateIOR called
    25.09.2017 09:00:24 1A98 T Endpoint found: 172.30.1.46:8193
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 I Successfully validated parent router's IOR
    25.09.2017 09:00:24 1A98 I Accessing parent
    25.09.2017 09:00:24 1A98 I SSL handshake done, local IP address = 172.30.20.79
    25.09.2017 09:00:24 1A98 I Parent is Router$pris
    25.09.2017 09:00:24 1A98 D Already registered with parent router
    25.09.2017 09:00:24 1A98 T RouterTableEntry::LogonToParentRouter
    25.09.2017 09:00:24 1A98 I RouterTableEntry::LogonToParentRouter() - logging on as active consumer
    25.09.2017 09:00:24 1A98 D RouterTableEntry::unsafe_enablePolling(): set polling interval to 681 seconds for Router$pris
    25.09.2017 09:00:24 1A98 I RouterTableEntry state (router, logging on): Router$pris is passive consumer, passive supplier
    25.09.2017 09:00:24 1A98 D RouterTableEntry::readyForNotifiedPoll(): await poll of Router$pris
    25.09.2017 09:00:24 1A98 I Logged on to parent router as Router$scopat-win10:441054
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::WriteReport
    25.09.2017 09:00:24 1B64 D GetterWorker::ProcessEntry() - polling Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1A98 I This computer is part of the domain PJL
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000004.msg" for [id=01C54536, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C54536
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C54536) to Router$pris
    25.09.2017 09:00:24 1B64 D RouterTableEntry::successfulGet(): re-started polling interval for Router$pris
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 09:00:24 1B64 D ~~~ IncomingSection: 0 strikes.
    25.09.2017 09:00:24 1B64 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1B64 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::DNSSection::WriteAsXML
    25.09.2017 09:00:24 1B64 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::DNSSection::WriteAsXML
    25.09.2017 09:00:24 1B64 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 09:00:24 1B64 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::CertificationSection::WriteAsXML
    25.09.2017 09:00:24 1B64 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::IncomingSection::WriteAsXML
    25.09.2017 09:00:24 1A98 T >>> StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::OutgoingSection::WriteAsXML
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::WriteAsXML
    25.09.2017 09:00:24 1A98 T <<< StatusReporting::StatusReporter::WriteReport
    25.09.2017 09:00:24 1940 I Sent message (id=01C54536) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000b.msg" for [id=01C7E837, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C7E837
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C7E837) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C7E837) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000c.msg" for [id=01C8416C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C8416C
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C8416C) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C8416C) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/0000000d.msg" for [id=01C8830C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C8830C
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C8830C) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C8830C) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000011.msg" for [id=01C8B165, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C8B165
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C8B165) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C8B165) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000012.msg" for [id=01C8B27C, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-EntityEvent]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C8B27C
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C8B27C) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C8B27C) to Router$pris
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Loaded "C:\ProgramData/Sophos/Remote Management System/3/Router/Envelopes/00000016.msg" for [id=01C8B6D7, origin=Router$scopat-win10:441054.Agent, dest=EM, type=EM-GetStatus-Reply]
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Envelope::GetOriginatorCert
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 D Expanded Envelope, id=01C8B6D7
    25.09.2017 09:00:24 1940 T Envelope::GetData
    25.09.2017 09:00:24 1940 T Envelope::Expand
    25.09.2017 09:00:24 1940 T Sending message (id=01C8B6D7) to Router$pris
    25.09.2017 09:00:24 1940 I Sent message (id=01C8B6D7) to Router$pris
    25.09.2017 09:00:24 0F48 I SSL handshake done, local IP address = 172.30.20.79
    25.09.2017 09:00:24 0F08 T NotifyConsumer::NotificationThreshold() called
    25.09.2017 09:00:24 0F08 T >>> StatusReporting::IncomingSection::ThresholdCall
    25.09.2017 09:00:24 0F08 D ~~~ IncomingSection: 0 strikes.
    25.09.2017 09:00:24 0F08 T <<< StatusReporting::IncomingSection::ThresholdCall
    25.09.2017 09:00:24 0F08 T >>> StatusReporting::StatusReporter::Done
    25.09.2017 09:00:24 0F08 T DNS            : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0F08 T Certification  : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0F08 T Incoming       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0F08 T Outgoing       : problem 0, changed 0, already reported 0
    25.09.2017 09:00:24 0F08 T <<< StatusReporting::StatusReporter::Done
    25.09.2017 09:00:29 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:29 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:29 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:29 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:34 18C0 T GetterThread::Process() checking table
    25.09.2017 09:00:34 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:34 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:34 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:34 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:39 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:39 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:39 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:39 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:44 18C0 T GetterThread::Process() checking table
    25.09.2017 09:00:44 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:44 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:44 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:44 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:49 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:49 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:49 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:49 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:54 18C0 T GetterThread::Process() checking table
    25.09.2017 09:00:54 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:54 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:54 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:54 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:00:59 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:00:59 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:00:59 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:00:59 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:04 18C0 T GetterThread::Process() checking table
    25.09.2017 09:01:04 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:04 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:04 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:04 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:09 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:09 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:09 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:09 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:14 18C0 T GetterThread::Process() checking table
    25.09.2017 09:01:14 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:14 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:14 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:14 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:19 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:19 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:19 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:19 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:24 18C0 T GetterThread::Process() checking table
    25.09.2017 09:01:24 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:24 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:24 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:24 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:29 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:29 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:29 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:29 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:34 1B80 T TimeoutThread::Process() checking table
    25.09.2017 09:01:34 18C0 T GetterThread::Process() checking table
    25.09.2017 09:01:34 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:34 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:34 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:34 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:39 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:39 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:39 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:39 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:44 18C0 T GetterThread::Process() checking table
    25.09.2017 09:01:44 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:44 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:44 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:44 1B88 T IPAddressSet::InitialiseWithHost() returns
    25.09.2017 09:01:49 1B88 T IPAddressSet::InitialiseWithHost() called
    25.09.2017 09:01:49 1B88 T Added host network address:172.30.20.79:0
    25.09.2017 09:01:49 1B88 T Added host network address:127.0.0.1:0
    25.09.2017 09:01:49 1B88 T IPAddressSet::InitialiseWithHost() returns

    _______________________________________________________________________________________________________________________

     

    Ian.

  • FYI:  I edited your reply and attached the full log as a file to make reading it easier.  Hope it helps.

     - - - - - - - - - - - -

    Communities Moderator, SOPHOS
    Knowledge Base  |  @SophosSupport  |  Video tutorials
    Remember to like a post.  If a post (on a question thread) solves your question use the 'This helped me' link.

  • Hi Ruckus,

    Many thanks for this which is much appreciated.

    Ian.

  • Hi Ian,

    Have you heard anything back from Sophos Support on this issue? I have submitted extracts to them from the Remote Management System Router Logs which bear some similarity to those you submitted, but I haven't had any response, even to acknowledge their receipt.

    Many thanks,

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Hi all,

    I have been comparing Registry settings on a PC displayed as 'disconnected' in SEC against one shown as 'connected'.

    One difference I can see is in HKEY_LOCAL_MACHINE\SOFTWARE\Wow6432Node\Sophos\Messaging System\Router. On a PC shown as 'connected' the entry HostIPToParent is displayed as a REG_DWORD value of 0x0a3f0f37 (171904823) or similar (differs slightly on 'connected' PCs).

    However, on all 'disconnected' PCs, this entry is shown as a REG_DWORD value of 0x00000000 (0).

    I have no idea if this is relevant to this issue, but thought I'd highlight it anyway.

    Best regards,

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Hello John P, Ian, and other interested parties,

    (I thought I've done so but) I've not yet explicitly said that verbose logging showed that

    • the adapter is considered already active (otherwise a check-loop is entered)
    • the first call to IPAddressSet::InitialiseWithHost() correctly adds both localhost and the actual IP4 address
    • either Resolving the root object adapter... or Creating MessageRouter CORBA object... take localhost as resolved IP

    Unless there some additional debugging option (which Support would have to reveal) further attempts from our (your) side to find or help in finding the prime reason are purportless (but perhaps educating). Inspecting other logs, network traces, registry and other comparisons will just show the (expected) consequences of the incorrectly set IOR - not why it has been incorrectly set in the first place. Development should know what happens at this point (and if necessary how to obtain actually helpful information).
    Even if you are able to find the cause on your own you'd likely have only the option to work around until RMS is updated: Delayed start, service restart, adapter disable/enable. IMO the first has the least side-effects.

    You can check the status of your case at Sophserv

    Christian

  • Hi John,

    Our last correspondence with Sophos was on Thursday evening when they advised that this issue had been escalated to one of the Level 2 Escalation Engineers.  This morning we emailed Sophos for an update and, to be honest, complain on the basis they only ever appear to respond when prompted. The outcome of this is that an engineer is now reviewing the escalation note and that this may include speaking to the Sophos GES/DEV team on our behalf.  Once again we referred them to this thread. 

    Ian.

  • Hi Christian,

    Thank you for your input, as usual it has proven quite helpful.

    Forgive me if I have been 'over-posting' in relation to this issue. I was hoping to gain some better understanding of what the underlying issue is and if anyone else had encountered something similar in their SEC instance.

    I have to say, however, that the response from Sophos Support (via Sophserv) has been less than stellar. I have updated the submitted support case a few times with my findings and have not received an update of any sort.

    Looks like we will go with the delayed start for the Sophos Message Router service as an interim.

    Many thanks and best regards,

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive

  • Cheers Ian,

    Thanks for the update. If I hear anything back on my end, I'll keep you posted.

    Best regards,

    John P

    2 x SG450 (Version 9.714-4)

    HA = Active-Passive