Important note about SSL VPN compatibility for 20.0 MR1 with EoL SFOS versions and UTM9 OS. Learn more in the release notes.

Thread Info
  • State Not Answered
  • +2 person also asked this people also asked this
  • Locked Locked
  • Replies 49 replies
  • Subscribers 45 subscribers
  • Views 8852 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Sophos Heartbeat - Red in XG but green in Central

Julian Cast

Hello,

we have continuous problem with the heartbeat for some users. 

The endpoint is green and fine but in central it's red. 

Here the last log during the problem (heartbeat log)

a 2021-06-23T06:45:27.764Z [5880:8000] - Received request to enable enhanced application control
a 2021-06-23T06:45:27.771Z [5880:8000] - Sending login status.
a 2021-06-23T06:45:28.098Z [5880:8000] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-23T06:45:28.138Z [5880:8000] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-23T06:45:41.410Z [5880:8000] - Sending health status: {"admin":1, "health":1, "service":1, "threat":1}
a 2021-06-23T07:15:11.868Z [5880:8000] - Received request to disable enhanced application control for C:\program files (x86)\google\chrome\application\chrome.exe
a 2021-06-23T10:22:33.571Z [5880:7476] - ----------------------------------------------------------------------------------------------------
a 2021-06-23T10:22:33.572Z [5880:7476] - Stopped Heartbeat
a 2021-06-23T10:22:33.572Z [5880:7476] - ----------------------------------------------------------------------------------------------------
a 2021-06-23T10:22:37.665Z [19648:19496] - ----------------------------------------------------------------------------------------------------
a 2021-06-23T10:22:37.666Z [19648:19496] - Starting Heartbeat version 1.11.194.0
a 2021-06-23T10:22:37.666Z [19648:19496] - ----------------------------------------------------------------------------------------------------
a 2021-06-23T10:22:38.124Z [19648:16596] - Connection succeeded.
a 2021-06-23T10:22:38.125Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-23T10:22:38.140Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.22 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T10:22:38.400Z [19648:16596] - Received request to enable enhanced application control
a 2021-06-23T10:22:38.400Z [19648:16596] - Sending login status.
a 2021-06-23T10:22:52.077Z [19648:16596] - Sending health status: {"health":3}
a 2021-06-23T10:51:43.762Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-23T11:31:11.576Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\google\chrome\application\chrome.exe
a 2021-06-23T12:44:45.877Z [19648:16596] - Received request to disable enhanced application control for C:\program files\internet explorer\iexplore.exe
a 2021-06-23T13:58:12.169Z [19648:16596] - Connection closed (network error).
a 2021-06-23T13:58:13.181Z [19648:16596] - Connection failed.
a 2021-06-23T14:08:02.495Z [19648:16596] - Connection succeeded.
a 2021-06-23T14:08:02.496Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-23T14:08:02.510Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.22 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T14:08:02.738Z [19648:16596] - Received request to enable enhanced application control
a 2021-06-23T14:08:02.741Z [19648:16596] - Sending login status.
a 2021-06-23T14:08:03.244Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\google\chrome\application\chrome.exe
a 2021-06-23T14:08:13.160Z [19648:16596] - Sending health status: {"health":3}
a 2021-06-23T14:54:57.625Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-23T14:54:57.655Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-23T15:31:08.146Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T15:31:15.057Z [19648:16596] - Connection closed (network error).
a 2021-06-23T15:31:37.141Z [19648:16596] - Connection failed.
a 2021-06-23T15:31:52.423Z [19648:16596] - Connection succeeded.
a 2021-06-23T15:31:52.423Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-23T15:31:52.438Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.9 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T15:31:52.450Z [19648:16596] - Connection closed (network error).
a 2021-06-23T15:31:53.728Z [19648:16596] - Connection succeeded.
a 2021-06-23T15:31:53.729Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-23T15:31:53.747Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.9 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T15:31:53.761Z [19648:16596] - Connection closed (network error).
a 2021-06-23T15:31:55.000Z [19648:16596] - Connection succeeded.
a 2021-06-23T15:31:55.000Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-23T15:31:55.015Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.9 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-23T15:31:55.145Z [19648:16596] - Received request to enable enhanced application control
a 2021-06-23T15:31:55.146Z [19648:16596] - Sending login status.
a 2021-06-23T15:32:03.612Z [19648:16596] - Sending health status: {"health":3}
a 2021-06-23T17:38:13.918Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\microsoft\edgeupdate\microsoftedgeupdate.exe
a 2021-06-23T21:41:06.153Z [19648:16596] - Connection closed (network error).
a 2021-06-24T06:29:22.504Z [19648:16596] - Connection failed.
a 2021-06-24T06:31:26.179Z [19648:16596] - Connection succeeded.
a 2021-06-24T06:31:26.179Z [19648:16596] - Connected to '3a343c11-a991-4d63-ab52-1df31f3ce352' at IP address 52.5.76.173 on port 8347
a 2021-06-24T06:31:26.193Z [19648:16596] - Sending network status. Active Interfaces:
MAC: 00:FF:39:01:DF:1B - INET: 192.168.181.21 - INET6: fe80::507c:e745:b4b8:e1e7
MAC: 24:41:8C:31:94:12 - INET: 192.168.1.3 - INET6: fe80::10a7:ca61:5e5e:2034
a 2021-06-24T06:31:26.483Z [19648:16596] - Received request to enable enhanced application control
a 2021-06-24T06:31:26.483Z [19648:16596] - Sending login status.
a 2021-06-24T06:31:27.846Z [19648:16596] - Sending health status: {"health":3}
a 2021-06-24T06:32:03.946Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-24T06:32:03.995Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\internet explorer\iexplore.exe
a 2021-06-24T06:32:33.202Z [19648:16596] - Received request to disable enhanced application control for C:\program files\internet explorer\iexplore.exe
a 2021-06-24T06:35:38.958Z [19648:16596] - Received request to disable enhanced application control for C:\program files (x86)\google\chrome\application\chrome.exe

We already contact the Sophos support... 1 month to have the reply from the support. You can imagin that we trying different ways to solve the problem, a momentary solution is re install Sophos but it's not for always.

Thank you !



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

    AS you can see, the heartbeat status switching every minutes ! In central it's green fixed... 

  • 0 in reply to Julian Cast

    that's the very same for us. and on the XG it's always flapping between 1 and 3 in heartbeat.log. Maybe this is happening when the computers are idle. It only happens for a small percentage of devices but I want to know why they appear risky to XG.

    I will mention your case number in my support case. Currently they want me to re-register the XG into central because they cannot put fwcm-heartbeatd.log into debug. See my post community.sophos.com/.../logging-heartbeat-vs-fwcm-heartbeatd-500-opcode-failed

  • 0 in reply to LHerzog

    I will try this command thank you

  • 0 in reply to LHerzog

    PS: The Flap should be better in MR5 with the CLI Change. docs.sophos.com/.../SystemCommands.html

    __________________________________________________________________________________________________________________

  • 0 in reply to Julian Cast

    I executed service fwcm-heartbeatd:debug -ds nosync

    But i have this error in the log??

    XG330_WP02_SFOS 18.0.5 MR-5-Build586# tail -f heartbeatd.log
2021-06-30 09:48:39 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:39 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:46 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:47 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:50 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:55 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:56 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:56 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:58 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:48:59 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:07 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:07 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:08 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:11 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:12 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System
2021-06-30 09:49:12 WARN Path.cpp[5602]:68 getExecutableFilename - Parsing executable filename failed. Falling back to full path: System

  • 0 in reply to Julian Cast

    For now i see in with an affected ip

    XG330_WP02_SFOS 18.0.5 MR-5-Build586# tail -f heartbeatd.log | grep 192.9.220.17
2021-06-30 09:53:17 INFO ModuleStatus.cpp[5602]:138 processMessageStatus - Status request received from endpoint: 7d4ab402-2192-43b1-8640-7d8cfa812909 (192.9.220.17) health: 1
2021-06-30 09:53:20 INFO ModuleStatus.cpp[5602]:138 processMessageStatus - Status request received from endpoint: 7d4ab402-2192-43b1-8640-7d8cfa812909 (192.9.220.17) health: 3

  • 0 in reply to LHerzog

    What i have in this log  fwcm-heartbeatd.log

    Jun 30 09:54:42.323 dbg Flags: in_progress:0, trx_sts:0, grp_id:00000000-0000-0000-0000-000000000000)
Jun 30 09:54:42.323 ntc trasaction_id status: (old:0, new:0), in_progress:0.
Jun 30 09:54:42.323 dbg Going in poll mode
Jun 30 09:55:42.220 dbg Time to punch heartbeat
Jun 30 09:55:42.220 dbg Time to punch heartbeat. Will send this data: 
        { "version": 2, "trxId": 0.0, "trxStatus": 0, "fwMetaData": { "capability": 7, "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "X", "ram": 12, "cpuCores": 4, "haStatus": "primary", "haPairApplianceKey": "C33101CQDD32TC9", "haMode": "active-passive" } }
Jun 30 09:55:42.220 dbg Preparing to send: 
        URL: https://utm-cloudstation-eu-central-1.prod.hydra.sophos.com/sophos/api/v1/firewalls/heartbeats/3a343c11-a991-4d63-ab52-1df31f3ce352
,       Data(321):{ "version": 2, "trxId": 0.0, "trxStatus": 0, "fwMetaData": { "capability": 7, "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "X", "ram": 12, "cpuCores": 4, "haStatus": "primary", "haPairApplianceKey": "C33101CQDD32TC9", "haMode": "active-passive" } }
Jun 30 09:55:42.293 dbg  Response code: '200'
Jun 30 09:55:42.294 dbg  Response content len: '547'
Jun 30 09:55:42.294 dbg  Response content: '{"trxId":0,"customerId":"X","forceSync":false,"skipTransaction":false,"inactiveStatus":false,"firstFailedTime":null,"trxStatus":0,"groupId":null,"exportXGConfig":false,"fwMetaData":{"fwVersion":"XG330_WP02_18.0.5.586","dispVersion":"XG330_WP02_SFOS 18.0.5 MR-5-Build586","hostname":"FWXGAF-WDC-01","ipAddress":null,"ram":12,"cpuCores":4,"haStatus":"primary","haMode":"active-passive","haPairApplianceKey":"C33101CQDD32TC9","capability":7},"receivedTime":"2021-06-30T07:55:42.278+00:00","transactionFailed":false}'
Jun 30 09:55:42.294 dbg HB POST returned:0, response_data:{ "trxId": 0, "customerId": "X", "forceSync": false, "skipTransaction": false, "inactiveStatus": false, "firstFailedTime": null, "trxStatus": 0, "groupId": null, "exportXGConfig": false, "fwMetaData": { "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "FWXGAF-WDC-01", "ipAddress": null, "ram": 12, "cpuCores": 4, "haStatus": "primary", "haMode": "active-passive", "haPairApplianceKey": "C33101CQDD32TC9", "capability": 7 }, "receivedTime": "2021-06-30T07:55:42.278+00:00", "transactionFailed": false }
Jun 30 09:55:42.294 dbg Flags: in_progress:0, trx_sts:0, grp_id:00000000-0000-0000-0000-000000000000)
Jun 30 09:55:42.294 ntc trasaction_id status: (old:0, new:0), in_progress:0.
Jun 30 09:55:42.294 dbg Going in poll mode

Reply
  • 0 in reply to LHerzog

    What i have in this log  fwcm-heartbeatd.log

    Jun 30 09:54:42.323 dbg Flags: in_progress:0, trx_sts:0, grp_id:00000000-0000-0000-0000-000000000000)
Jun 30 09:54:42.323 ntc trasaction_id status: (old:0, new:0), in_progress:0.
Jun 30 09:54:42.323 dbg Going in poll mode
Jun 30 09:55:42.220 dbg Time to punch heartbeat
Jun 30 09:55:42.220 dbg Time to punch heartbeat. Will send this data: 
        { "version": 2, "trxId": 0.0, "trxStatus": 0, "fwMetaData": { "capability": 7, "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "X", "ram": 12, "cpuCores": 4, "haStatus": "primary", "haPairApplianceKey": "C33101CQDD32TC9", "haMode": "active-passive" } }
Jun 30 09:55:42.220 dbg Preparing to send: 
        URL: https://utm-cloudstation-eu-central-1.prod.hydra.sophos.com/sophos/api/v1/firewalls/heartbeats/3a343c11-a991-4d63-ab52-1df31f3ce352
,       Data(321):{ "version": 2, "trxId": 0.0, "trxStatus": 0, "fwMetaData": { "capability": 7, "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "X", "ram": 12, "cpuCores": 4, "haStatus": "primary", "haPairApplianceKey": "C33101CQDD32TC9", "haMode": "active-passive" } }
Jun 30 09:55:42.293 dbg  Response code: '200'
Jun 30 09:55:42.294 dbg  Response content len: '547'
Jun 30 09:55:42.294 dbg  Response content: '{"trxId":0,"customerId":"X","forceSync":false,"skipTransaction":false,"inactiveStatus":false,"firstFailedTime":null,"trxStatus":0,"groupId":null,"exportXGConfig":false,"fwMetaData":{"fwVersion":"XG330_WP02_18.0.5.586","dispVersion":"XG330_WP02_SFOS 18.0.5 MR-5-Build586","hostname":"FWXGAF-WDC-01","ipAddress":null,"ram":12,"cpuCores":4,"haStatus":"primary","haMode":"active-passive","haPairApplianceKey":"C33101CQDD32TC9","capability":7},"receivedTime":"2021-06-30T07:55:42.278+00:00","transactionFailed":false}'
Jun 30 09:55:42.294 dbg HB POST returned:0, response_data:{ "trxId": 0, "customerId": "X", "forceSync": false, "skipTransaction": false, "inactiveStatus": false, "firstFailedTime": null, "trxStatus": 0, "groupId": null, "exportXGConfig": false, "fwMetaData": { "fwVersion": "XG330_WP02_18.0.5.586", "dispVersion": "XG330_WP02_SFOS 18.0.5 MR-5-Build586", "hostname": "FWXGAF-WDC-01", "ipAddress": null, "ram": 12, "cpuCores": 4, "haStatus": "primary", "haMode": "active-passive", "haPairApplianceKey": "C33101CQDD32TC9", "capability": 7 }, "receivedTime": "2021-06-30T07:55:42.278+00:00", "transactionFailed": false }
Jun 30 09:55:42.294 dbg Flags: in_progress:0, trx_sts:0, grp_id:00000000-0000-0000-0000-000000000000)
Jun 30 09:55:42.294 ntc trasaction_id status: (old:0, new:0), in_progress:0.
Jun 30 09:55:42.294 dbg Going in poll mode

Children
No Data
Unfiltered HTML