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

Impact on Intercept-X Heartbeat after Firewall Heartbeat Certificate renewal


Hi,

on a small remote location with XG Firewall the XG Heartbeat Certificate changed over the weekend.

Today the computers were powered on and heartbeat was not working on them so some firewall rules with HB requirement did not work.

A computer that has been left powered on over the weekend was fine today. So it was able to pick the new cert.

All Sophos / Sophos Central communication, DNS, DHCP, NTP etc. has no HB requirement on the FW rules.


To get one of the workstations working immediately I reinstalled the Intercept-X agent over the existing installation. After reboot HB was working immediately.
I already knew this workaround from the same issue when upgrading an other firewall in Janary 2021.

An other machine there fixed itself after it was running for some hours with failing heartbeat but only after a manual reboot.

I think this is just a client / Sophos Central issue that the client does not pick the new firewall HB certificate from Sophos Central immediately but that it does after many hours of just sitting there without heartbeat.

I'd like to know the expected or designed (by Sophos) impact or behaviour on the Intercept-X client  after the change of the certificate. I wonder why we still ran into a situation that we already had at our HQ with many hours struggling around with support on case 03540279.

Agentversions:

client HB log where EP has been re-installed:

2022-07-20T11:56:29.733Z [14700:13316] A Connection succeeded.
2022-07-20T11:56:29.735Z [14700:13316] A Connected to '040dxxxx-xxxx-xxxx-xxxx-xxxx768472f1' at IP address 52.5.76.173 on port 8347
2022-07-20T11:56:29.867Z [14700:15804] A Inactive Interfaces changed.
2022-07-20T11:56:29.868Z [14700:15804] A Active Interfaces:
MAC: 68:84:7E:71:7E:43 - INET: 192.168.48.25 - INET6: fe80::xxxx:xxxx:xxxx:1264
2022-07-20T11:56:29.869Z [14700:13316] A Sending network status
2022-07-20T11:56:29.871Z [14700:13316] A The network status has changed, the Firewall may disconnect.
2022-07-20T11:56:29.873Z [14700:13316] A Received request to enable enhanced application control
2022-07-20T11:56:29.875Z [14700:13316] A Sending endpoint state list request
2022-07-20T11:56:29.876Z [14700:13316] A Received response to endpoint state list request, size: 0
2022-07-20T11:56:29.953Z [14700:13316] A Sending login status.
2022-07-20T11:56:29.956Z [14700:13316] A User: windowsusername
2022-07-20T11:56:31.461Z [14700:13316] A Sending health status: {"admin":1,"health":1,"service":1,"threat":1,"threatService":1}
2022-07-20T12:02:02.227Z [14700:13316] A Received request to disable enhanced application control for C:\program files (x86)\microsoft\edgeupdate\microsoftedgeupdate.exe
2022-07-21T05:57:00.513Z [14700:13316] A Sending login status.
2022-07-21T05:57:00.515Z [14700:13316] A User:
2022-07-21T05:57:12.418Z [14700:13316] A Connection closed (network error).
2022-07-21T05:57:13.474Z [14700:13316] A Connection succeeded.
2022-07-21T05:57:13.476Z [14700:13316] A Connected to '040dxxxx-xxxx-xxxx-xxxx-xxxx768472f1' at IP address 52.5.76.173 on port 8347
2022-07-21T05:57:13.502Z [14700:13316] A Sending network status
2022-07-21T05:57:13.504Z [14700:13316] A The network status has changed, the Firewall may disconnect.
2022-07-21T05:57:13.523Z [14700:13316] A Received request to enable enhanced application control
2022-07-21T05:57:13.525Z [14700:13316] A Sending endpoint state list request
2022-07-21T05:57:13.527Z [14700:13316] A Sending login status.
2022-07-21T05:57:13.528Z [14700:13316] A User:
2022-07-21T05:57:13.530Z [14700:13316] A Received response to endpoint state list request, size: 0
2022-07-21T05:57:17.972Z [14700:13316] A Received request to disable enhanced application control for C:\program files (x86)\microsoft\edgeupdate\microsoftedgeupdate.exe
2022-07-21T05:57:20.850Z [14700:13316] A Sending health status: {"admin":1,"health":1,"service":1,"threat":1,"threatService":1}
2022-07-21T05:59:00.560Z [14700:13316] A Sending login status.
2022-07-21T05:59:00.561Z [14700:13316] A User: windowsusername
#########
FW HB Certificate changed here
#########
....
2022-07-25T06:02:56.008Z [14700:13316] A Sending login status.
2022-07-25T06:02:56.024Z [14700:13316] A User:
2022-07-25T06:02:56.950Z [14700:13316] A Connection closed (network error).
2022-07-25T06:02:57.955Z [14700:13316] A Connection failed.
2022-07-25T06:03:12.994Z [14700:13316] E TLS authentication failed after connecting.
....
2022-07-25T06:03:12.994Z [14700:13316] E TLS authentication failed after connecting.
2022-07-25T08:31:46.841Z [14700:15416] A ----------------------------------------------------------------------------------------------------
2022-07-25T08:31:46.844Z [14700:15416] A Stopped Heartbeat
2022-07-25T08:31:46.846Z [14700:15416] A ----------------------------------------------------------------------------------------------------
2022-07-25T08:31:47.500Z [15640:11424] A ----------------------------------------------------------------------------------------------------
2022-07-25T08:31:47.502Z [15640:11424] A Starting Heartbeat version 1.15.869.0
2022-07-25T08:31:47.503Z [15640:11424] A ----------------------------------------------------------------------------------------------------
2022-07-25T08:31:47.553Z [15640:13628] E TLS authentication failed after connecting.

#########
Intercept X reinstalled here
#########

2022-07-25T09:04:19.072Z [ 7604:17280] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:04:19.073Z [ 7604:17280] A Starting Heartbeat version 1.15.869.0
2022-07-25T09:04:19.075Z [ 7604:17280] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:04:19.129Z [ 7604: 2784] E TLS authentication failed after connecting.
2022-07-25T09:15:37.139Z [ 7604:16060] A The connection configuration has changed. Reloading settings.
2022-07-25T09:15:37.146Z [ 7604:16060] A The connection configuration has changed. Reloading settings.
2022-07-25T09:15:52.402Z [ 7604: 2784] A Connection succeeded.
2022-07-25T09:15:52.404Z [ 7604: 2784] A Connected to '538bxxxx-xxxx-xxxx-xxxx-xxxx1e7efb56' at IP address 52.5.76.173 on port 8347
2022-07-25T09:15:52.852Z [ 7604:12812] A Inactive Interfaces changed.
2022-07-25T09:15:52.854Z [ 7604:12812] A Active Interfaces:
MAC: 68:84:7E:71:7E:43 - INET: 192.168.48.25 - INET6: fe80::xxxx:xxxx:xxxx:1264
2022-07-25T09:15:52.855Z [ 7604: 2784] A Sending network status
2022-07-25T09:15:52.857Z [ 7604: 2784] A The network status has changed, the Firewall may disconnect.
2022-07-25T09:15:52.859Z [ 7604: 2784] A Received request to enable enhanced application control
2022-07-25T09:15:52.860Z [ 7604: 2784] A Sending endpoint state list request
2022-07-25T09:15:52.864Z [ 7604: 2784] A Received response to endpoint state list request, size: 0
2022-07-25T09:15:52.865Z [ 7604: 2784] A Sending login status.
2022-07-25T09:15:52.867Z [ 7604: 2784] A User: windowsusername
2022-07-25T09:16:04.957Z [ 7604: 2784] A Sending health status: {"admin":1,"health":1,"service":1,"threat":1,"threatService":1}
2022-07-25T09:17:27.201Z [ 7604: 2784] A Received request to disable enhanced application control for C:\program files (x86)\microsoft\edge\application\msedge.exe
2022-07-25T09:18:22.720Z [ 7604:17280] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:18:22.723Z [ 7604:17280] A Stopped Heartbeat
2022-07-25T09:18:22.725Z [ 7604:17280] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:18:25.162Z [16176:16988] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:18:25.164Z [16176:16988] A Starting Heartbeat version 1.15.869.0
2022-07-25T09:18:25.165Z [16176:16988] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:18:25.221Z [16176:10408] A Connection succeeded.
2022-07-25T09:18:25.223Z [16176:10408] A Connected to '538bxxxx-xxxx-xxxx-xxxx-xxxx1e7efb56' at IP address 52.5.76.173 on port 8347
2022-07-25T09:18:25.254Z [16176:15152] A Inactive Interfaces changed.
2022-07-25T09:18:25.256Z [16176:15152] A Active Interfaces:
MAC: 68:84:7E:71:7E:43 - INET: 192.168.48.25 - INET6: fe80::xxxx:xxxx:xxxx:1264
2022-07-25T09:18:25.257Z [16176:10408] A Sending network status
2022-07-25T09:18:25.260Z [16176:10408] A The network status has changed, the Firewall may disconnect.
2022-07-25T09:18:25.268Z [16176:10408] A Received request to enable enhanced application control
2022-07-25T09:18:25.269Z [16176:10408] A Sending endpoint state list request
2022-07-25T09:18:25.272Z [16176:10408] A Received response to endpoint state list request, size: 0
2022-07-25T09:18:25.274Z [16176:10408] A Sending login status.
2022-07-25T09:18:25.276Z [16176:10408] A User: windowsusername
2022-07-25T09:18:25.388Z [16176:10408] A Sending health status: {"admin":1,"health":1,"service":1,"threat":1,"threatService":1}
2022-07-25T09:18:38.718Z [16176:10408] A Received request to disable enhanced application control for C:\program files (x86)\microsoft\edge\application\msedge.exe

client HB log of machine rebooted after some hours without heartbeat:

2022-07-25T05:33:40.004Z [ 8032: 6840] A Connection closed (network error).
2022-07-25T05:33:41.022Z [ 8032: 6840] A Connection failed.
2022-07-25T05:33:56.074Z [ 8032: 6840] E TLS authentication failed after connecting.
2022-07-25T05:38:21.420Z [ 4316: 4820] A ----------------------------------------------------------------------------------------------------
2022-07-25T05:38:21.422Z [ 4316: 4820] A Starting Heartbeat version 1.15.869.0
2022-07-25T05:38:21.424Z [ 4316: 4820] A ----------------------------------------------------------------------------------------------------
2022-07-25T05:38:21.497Z [ 4316: 5668] E TLS authentication failed after connecting.
2022-07-25T05:43:03.796Z [ 4260: 4692] A ----------------------------------------------------------------------------------------------------
2022-07-25T05:43:03.798Z [ 4260: 4692] A Starting Heartbeat version 1.15.869.0
2022-07-25T05:43:03.799Z [ 4260: 4692] A ----------------------------------------------------------------------------------------------------
2022-07-25T05:43:03.903Z [ 4260: 5616] E TLS authentication failed after connecting.
2022-07-25T07:49:24.286Z [ 4200: 4564] A ----------------------------------------------------------------------------------------------------
2022-07-25T07:49:24.288Z [ 4200: 4564] A Starting Heartbeat version 1.15.869.0
2022-07-25T07:49:24.290Z [ 4200: 4564] A ----------------------------------------------------------------------------------------------------
2022-07-25T07:49:24.387Z [ 4200: 5528] E TLS authentication failed after connecting.
2022-07-25T09:01:18.847Z [ 4200: 5528] A Connection failed.
2022-07-25T09:01:53.961Z [ 4200: 5528] E TLS authentication failed after connecting.
########
reboot here
########
2022-07-25T09:31:02.940Z [ 4232: 4720] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:31:02.943Z [ 4232: 4720] A Starting Heartbeat version 1.15.869.0
2022-07-25T09:31:02.944Z [ 4232: 4720] A ----------------------------------------------------------------------------------------------------
2022-07-25T09:31:03.058Z [ 4232: 5680] E TLS authentication failed after connecting.
2022-07-25T09:35:05.514Z [ 4232: 5660] A The connection configuration has changed. Reloading settings.
2022-07-25T09:35:05.521Z [ 4232: 5660] A The connection configuration has changed. Reloading settings.
2022-07-25T09:35:33.691Z [ 4232: 5680] A Connection succeeded.
2022-07-25T09:35:33.693Z [ 4232: 5680] A Connected to '538bxxxx-xxxx-xxxx-xxxx-xxxx1e7efb56' at IP address 52.5.76.173 on port 8347
2022-07-25T09:35:33.822Z [ 4232: 5684] A Inactive Interfaces changed.
2022-07-25T09:35:33.824Z [ 4232: 5684] A Active Interfaces:
MAC: 68:84:7E:72:35:7A - INET: 192.168.xxx.xxx - INET6: fe80::xxx:xxxx:xxxx:f604
2022-07-25T09:35:33.826Z [ 4232: 5680] A Sending network status
2022-07-25T09:35:33.827Z [ 4232: 5680] A The network status has changed, the Firewall may disconnect.
2022-07-25T09:35:33.830Z [ 4232: 5680] A Received request to enable enhanced application control
2022-07-25T09:35:33.831Z [ 4232: 5680] A Sending endpoint state list request
2022-07-25T09:35:33.834Z [ 4232: 5680] A Received response to endpoint state list request, size: 0
2022-07-25T09:35:33.837Z [ 4232: 5680] A Sending login status.
2022-07-25T09:35:33.838Z [ 4232: 5680] A User: windowsusername
2022-07-25T09:35:47.125Z [ 4232: 5680] A Sending health status: {"admin":1,"health":1,"service":1,"threat":1,"threatService":1}

FW HB Log:

2022-07-25 11:13:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:13:52 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:13:52 WARN HBSession.cpp[10056]:341 bufferDisconnectEvent - Incoming connection from 192.168.xxx.xxx failed. SSL error: SSL routines:ssl3_read_bytes tlsv1 alert internal error
2022-07-25 11:14:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:14:52 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:14:52 WARN HBSession.cpp[10056]:341 bufferDisconnectEvent - Incoming connection from 192.168.xxx.xxx failed. SSL error: SSL routines:ssl3_read_bytes tlsv1 alert internal error
#########
Intercept-X reinstalled on EP 5dbcff9b here
#########
2022-07-25 11:15:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:15:52 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:15:52 INFO HBSessionHandler.cpp[10056]:135 findPinnedEndpointIdentity - Number of sessions: 2
2022-07-25 11:15:52 INFO HBSession.cpp[10056]:502 logNewSession - New Session: [192.168.xxx.xxx]:31474 connected
2022-07-25 11:15:52 INFO EndpointStorage.cpp[10056]:114 endpoint_connectivity_cb - Connectivity changed for <1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b>: <3> -> <1>
2022-07-25 11:15:52 INFO ModuleSacFirst.cpp[10056]:95 sendEacMessage - send EacSwitchRequest to endpoint (IP=192.168.xxx.xxx)
2022-07-25 11:15:52 INFO EpStateListBroker.cpp[10056]:56 markEndpointForUpdates - Endpoint marked for receiving Stonewall updates: 1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b(192.168.xxx.xxx)
2022-07-25 11:16:04 INFO ModuleStatus.cpp[10056]:138 processMessageStatus - Status request received from endpoint: 1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b (192.168.xxx.xxx) health: 1
2022-07-25 11:16:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 2
2022-07-25 11:17:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 2
2022-07-25 11:17:26 INFO SacProcessor.cpp[10056]:64 discardApp - Sent switchOffConnectionInfo request to endpoint: <1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b>, Application path :C:\134program files (x86)\134microsoft\134edge\134application\134msedge.exe
2022-07-25 11:18:23 WARN HBSession.cpp[10056]:341 bufferDisconnectEvent - Incoming connection from 192.168.xxx.xxx failed. SSL error:
2022-07-25 11:18:23 INFO EndpointStorage.cpp[10056]:114 endpoint_connectivity_cb - Connectivity changed for <1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b>: <1> -> <5>
2022-07-25 11:18:24 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 1
2022-07-25 11:18:24 INFO HBSessionHandler.cpp[10056]:135 findPinnedEndpointIdentity - Number of sessions: 2
2022-07-25 11:18:24 INFO HBSession.cpp[10056]:502 logNewSession - New Session: [192.168.xxx.xxx]:51954 connected
2022-07-25 11:18:25 INFO EndpointStorage.cpp[10056]:114 endpoint_connectivity_cb - Connectivity changed for <1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b>: <5> -> <1>
2022-07-25 11:18:25 INFO ModuleSacFirst.cpp[10056]:95 sendEacMessage - send EacSwitchRequest to endpoint (IP=192.168.xxx.xxx)
2022-07-25 11:18:25 INFO EpStateListBroker.cpp[10056]:56 markEndpointForUpdates - Endpoint marked for receiving Stonewall updates: 1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b(192.168.xxx.xxx)
2022-07-25 11:18:25 INFO ModuleStatus.cpp[10056]:138 processMessageStatus - Status request received from endpoint: 1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b (192.168.xxx.xxx) health: 1
2022-07-25 11:18:25 INFO HBSessionHandler.cpp[10056]:108 removeDirtySessions - Number of sessions: 2
2022-07-25 11:18:38 INFO SacProcessor.cpp[10056]:64 discardApp - Sent switchOffConnectionInfo request to endpoint: <1108xxxx-xxxx-xxxx-xxxx-xxxx5dbcff9b>, Application path



This thread was automatically locked due to age.
Parents
  • Hi LHerzog, 

    I want to clarify if rebooting a device exhibiting this issue allows the system to obtain the new certificate or if a reinstall is necessary before the reboot?

    If you were to clone the existing policy you have in Sophos Central with Heartbeat enabled, then apply the cloned policy to any problematic devices, does this allow heartbeat to return to normal? I suspect this issue is related to a full policy render (or lack thereof)  on the endpoint, which allows it to obtain the new certificate. 

    Kushal Lakhan
    Team Lead, Global Community Support
    Connect with Sophos Support, get alerted, and be informed.
    If a post solves your question, please use the "Verify Answer" button.
    The New Home of Sophos Support Videos!  Visit Sophos Techvids
Reply
  • Hi LHerzog, 

    I want to clarify if rebooting a device exhibiting this issue allows the system to obtain the new certificate or if a reinstall is necessary before the reboot?

    If you were to clone the existing policy you have in Sophos Central with Heartbeat enabled, then apply the cloned policy to any problematic devices, does this allow heartbeat to return to normal? I suspect this issue is related to a full policy render (or lack thereof)  on the endpoint, which allows it to obtain the new certificate. 

    Kushal Lakhan
    Team Lead, Global Community Support
    Connect with Sophos Support, get alerted, and be informed.
    If a post solves your question, please use the "Verify Answer" button.
    The New Home of Sophos Support Videos!  Visit Sophos Techvids
Children
  • So far I monitored:

    reinstalling Intercept-X pulls new certificate immediately

    restarting Endpoint may work after some time (hours). It does not seem to pull the new certificate immediately after the firewall generated the new certificate

    If you were to clone the existing policy you have in Sophos Central with Heartbeat enabled, then apply the cloned policy to any problematic devices, does this allow heartbeat to return to normal?

    I do not understand what you mean here. And I cannot test this because all clients have been manually fixed yesterday.

    I'm really looking forward to an answer to my question:

    I'd like to know the expected or designed (by Sophos) impact or behaviour on the Intercept-X client  after the change of the certificate.

  • SFOS will push the certificate to Central. Central will render the Certificate within the policies. 

    Clients will pull all clients of this Tenant. 

    __________________________________________________________________________________________________________________

  • Thank you

    and in which time frame should this all happen?

    Or more exactly, how log should it take for a client to pick the new certificate from its policy?

    Is there an intended requirement for a client reboot?

    I'm not aware of a policy for Heartbeat - this is integrated / backend stuff, is'nt it?

  • I cannot answer this question. This depends on the scaling of Central. General speaking Central tries to run those renewal process as fast as possible. I could reproduce multiple of those scenarios within 1-2 minutes. 

    In V19.0 MR1 was a fix for those scenarios with a large number of endpoints: 

    • Synchronized Security - Improved Sophos Central Firewall Management resilience in environments with thousands of endpoint certificates being used for Synchronized Security Heartbeat.

    __________________________________________________________________________________________________________________

  • Yes, I've read this in the release notes. in our recent case there are only 3 computers connected behind a XG106. I'd expect there is no need nor computer count to scale anything.

    Thanks for giving the information you have.

  • anyone else from Sophos who can share insights into the cert renewal process, please? The documentation does not cover the HB cert renewal process. And I get a pain in my stomach when I think about that our HQ Firewall Heartbeat certificate expiring in January.

    That article is the only one handling the HB certificate renewal. https://support.sophos.com/support/s/article/KB-000037006?language=en_US&c__displayLanguage=en_US

    There should be more knowledge.

  • I suggest opening a support case so that this can be looked into. Although the issue is no longer present, it would be best to determine the root cause of the issues you encountered.

    You may want to check over MCS communication around the time the XG certificate renewed to see if any errors are present. Ensuring that DNS was reachable from the endpoints when they reported a bad heartbeat status would also be good to check. From the symptoms you've mentioned, the endpoints should have received the updated XG certificate from Sophos Central.

    Endpoints will check in with Sophos Central to ensure they have the latest policies every 2 minutes, so this issue should not have occurred for an extended period as you encountered in your environment.

    You're welcome to contact me via PM with your case number so we can ensure it’s progressing reasonably.

    Kushal Lakhan
    Team Lead, Global Community Support
    Connect with Sophos Support, get alerted, and be informed.
    If a post solves your question, please use the "Verify Answer" button.
    The New Home of Sophos Support Videos!  Visit Sophos Techvids