temporary MCS Status Code 503, connection timeout, Dropping connection after error, Live Discover issue

We've this occasionally on Windows hosts. No new issue, though.

I cannot run live query when the machine is in that state.

Here a Server 2019.

On XG Fw I can see it communicating:

SDU https://sdu-feedback.sophos.com/prod/f90ff178-b4db-4b1e-90b2-e63fdc78fe54_2022-01-12-17-19-21.zip

MCSClient.log

2022-01-12T17:08:54.816Z [ 2956: 3800] I POST https://mcs2-cloudstation-eu-central-1.prod.hydra.sophos.com:443/sophos/management/ep/v2/data_feed/device/f90ff178-b4db-xxxx-90b2-xxxxxxxxxxx/feed_id/scheduled_query
2022-01-12T17:08:54.832Z [ 2956: 3800] I 200 : sent=1119 rcvd=0 elapsed=15ms
2022-01-12T17:08:54.832Z [ 2956: 3800] I Feed channel scheduled_query: uploading file C:\ProgramData\Sophos\Management Communications System\Endpoint\Channels\LiveQueryScheduled\Incoming\scheduled-20220112170839584.json result 0 purge false
2022-01-12T17:08:54.832Z [ 2956: 3800] I Feed channel scheduled_query: uploaded file C:\ProgramData\Sophos\Management Communications System\Endpoint\Channels\LiveQueryScheduled\Incoming\scheduled-20220112170839584.json
2022-01-12T17:08:54.833Z [ 2956: 3800] I Establishing push connection
2022-01-12T17:08:54.838Z [ 2956: 3800] I (async) GET https://mcs-push-server-eu-central-1.prod.hydra.sophos.com:443/ps/push/endpoint/9ff01f87-4bbd-xxxx-092b-xxxxxxxxxxx
2022-01-12T17:08:55.929Z [ 2956:  704] I (async) 503 : conntime=1091ms
2022-01-12T17:08:55.929Z [ 2956: 3800] W (async) connection timeout
2022-01-12T17:08:55.931Z [ 2956: 3800] W [push]: error creating async stream: 0
2022-01-12T17:08:55.933Z [ 2956: 3800] I [push]: Dropping connection after error
2022-01-12T17:09:50.952Z [ 2956: 3800] I GET https://mcs2-cloudstation-eu-central-1.prod.hydra.sophos.com:443/sophos/management/ep/commands/applications/ALC;AMSI;CORC;CORE;EFW;FIM;HBT;HMPA;LiveQuery;LiveTerminal;MCS;MDR;NTP;SAV;SDU;SHS;SWC;UI;APPSPROXY/endpoint/9ff01f87-4bbd-xxxx-092b-xxxxxxxxxxx
2022-01-12T17:09:51.978Z [ 2956: 3800] I 503 : sent=0 rcvd=0 elapsed=1025ms
2022-01-12T17:09:51.978Z [ 2956: 3800] I Dropping connection after error
2022-01-12T17:09:51.978Z [ 2956: 3800] I [backoff] waiting 1145s (880s + 265s skew) after failures: 4
2022-01-12T17:14:52.124Z [ 2956: 3832] I service tamper protection disabled
2022-01-12T17:14:55.081Z [ 2956: 3800] I User sessions changed: +(userDomain=VILLABOSCH, userName=lherzogsrvadm, userPrincipalName=lherzogsrvadm@villa-bosch.de, userSid=S-1-5-21-1803570019-140194396-1541874228-18048, state=0, type=1)
2022-01-12T17:14:55.091Z [ 2956: 3800] I [connect] trying server https://mcs2-cloudstation-eu-central-1.prod.hydra.sophos.com/sophos/management/ep
2022-01-12T17:14:55.091Z [ 2956: 3800] I [connect] trying direct connection without a proxy
2022-01-12T17:14:55.091Z [ 2956: 3800] I GET https://mcs2-cloudstation-eu-central-1.prod.hydra.sophos.com:443/sophos/management/ep
2022-01-12T17:15:11.175Z [ 2956: 3800] I 200 : sent=0 rcvd=168 elapsed=16082ms

MCSAgent.log

2022-01-12T16:51:54.334Z [ 2924: 4236] I [UI] UI: Updating registry key SOFTWARE\Sophos\Sophos UI\AdapterNotifications\APPSPROXY
2022-01-12T16:51:54.334Z [ 2924: 4236] I [UI] UI: UpdateAdapterNotification registry updated for adapter APPSPROXY
2022-01-12T17:09:52.658Z [ 2924: 2928] I Session Change Notification: Remote session connected
2022-01-12T17:09:54.621Z [ 2924: 2928] I Session Change Notification: User logged on
2022-01-12T17:09:54.909Z [ 2924: 4236] I UserInfo has changed: saving and broadcasting to listening adapters
2022-01-12T17:09:54.921Z [ 2924: 4236] I [AMSI] Received property changed from: APPSPROXY
2022-01-12T17:09:54.921Z [ 2924: 4236] I [HBT] Heartbeat adapter: AdapterPropertiesChanged notification received from APPSPROXY, check user info
2022-01-12T17:09:54.921Z [ 2924: 4236] I [HBT] Heartbeat adapter: Set user info
2022-01-12T17:09:54.921Z [ 2924: 4236] I [UI] UI: AdapterPropertiesChanged notification received from APPSPROXY
2022-01-12T17:09:54.921Z [ 2924: 4236] I [UI] UI: Set key to SOFTWARE\Sophos\Sophos UI\AdapterNotifications\, trying to match adapter APPSPROXY
2022-01-12T17:09:54.921Z [ 2924: 4236] I [UI] UI: Updating registry key SOFTWARE\Sophos\Sophos UI\AdapterNotifications\APPSPROXY
2022-01-12T17:09:54.922Z [ 2924: 4236] I [UI] UI: UpdateAdapterNotification registry updated for adapter APPSPROXY
2022-01-12T17:10:25.198Z [ 2924:  112] I [UI] UI: Received request from UI: {"get":["CORE.tamperProtectionEnabled"]}
2022-01-12T17:10:25.198Z [ 2924:  112] I [UI] UI: Processing get request from UI: CORE.tamperProtectionEnabled
2022-01-12T17:10:25.199Z [ 2924:  112] I [UI] UI: Get request CORE.tamperProtectionEnabled returned value true and result 0
2022-01-12T17:10:25.261Z [ 2924: 4740] I [UI] UI: Received request from UI: {"authorisation":{"UI.token": "xxxx"},"action":{"SAV.requeststate":"[EXTRAINFO]"}}
2022-01-12T17:10:25.261Z [ 2924: 4740] I [UI] UI: SAV requeststate action does not require authentication
2022-01-12T17:10:25.261Z [ 2924: 4740] I [UI] UI: Processing action request from UI: SAV.requeststate
2022-01-12T17:10:25.261Z [ 2924: 4740] I [UI] UI: AdapterActionProgress notification received from SAV for action scanStatus :: SAV scan is not in progress
2022-01-12T17:10:25.261Z [ 2924: 4740] I [UI] UI: Set key to SOFTWARE\Sophos\Sophos UI\AdapterNotifications\, trying to match adapter SAV
2022-01-12T17:10:25.325Z [ 2924: 4184] I [UI] UI: Received request from UI: {"get":["NTP.isolated"]}
2022-01-12T17:10:25.325Z [ 2924: 4184] I [UI] UI: Processing get request from UI: NTP.isolated
2022-01-12T17:10:25.326Z [ 2924: 4184] I [NTP] NTP adapter [StatusReporter::CalculateStatus]: Returning newly calculated status of revId: xxxxxxxxxxxxxxxxx res: Same
2022-01-12T17:10:25.327Z [ 2924: 4184] I [NTP] NTP adapter [NTPAdapter::GetAdapterProperty]: Got property 'isolated': false
2022-01-12T17:10:25.327Z [ 2924: 4184] I [UI] UI: Get request NTP.isolated returned value false and result 0
2022-01-12T17:10:25.386Z [ 2924: 7880] I [UI] UI: Received request from UI: {"get":["NTP.isolated"]}
2022-01-12T17:10:25.386Z [ 2924: 7880] I [UI] UI: Processing get request from UI: NTP.isolated
2022-01-12T17:10:25.387Z [ 2924: 7880] I [NTP] NTP adapter [StatusReporter::CalculateStatus]: Returning newly calculated status of revId: xxxxxxxxxxxxxxxxx res: Same
2022-01-12T17:10:25.387Z [ 2924: 7880] I [NTP] NTP adapter [NTPAdapter::GetAdapterProperty]: Got property 'isolated': false
2022-01-12T17:10:25.387Z [ 2924: 7880] I [UI] UI: Get request NTP.isolated returned value false and result 0
2022-01-12T17:10:29.013Z [ 2924: 7860] I [UI] UI: Received request from UI: {"get":["CORE.tamperProtectionEnabled"]}
2022-01-12T17:10:29.013Z [ 2924: 7860] I [UI] UI: Processing get request from UI: CORE.tamperProtectionEnabled
2022-01-12T17:10:29.013Z [ 2924: 7860] I [UI] UI: Get request CORE.tamperProtectionEnabled returned value true and result 0
2022-01-12T17:10:29.186Z [ 2924:  756] I [UI] UI: Received request from UI: {"get":["APPSPROXY.suspended"]}
2022-01-12T17:10:29.186Z [ 2924:  756] I [UI] UI: Processing get request from UI: APPSPROXY.suspended
2022-01-12T17:10:29.197Z [ 2924:  756] I [UI] UI: Get request APPSPROXY.suspended returned value false and result 0
2022-01-12T17:14:48.985Z [ 2924: 8376] I [UI] UI: Received request from UI: {"get":["UI.tokenFor.xxxx","CORE.tamperProtectionEnabled"]}
2022-01-12T17:14:48.985Z [ 2924: 8376] I [UI] UI: Processing get request from UI: CORE.tamperProtectionEnabled

The Sophos Management Communications System client service has received an HTTP status 503 from the server. This might indicate that action is necessary.

The issue just started after I logged on to the Server via RDP Remote Desktop.

Can be seen here 17:49 logon, at 17:50 MCS communication issue.



changed topic to live discover issue
[bearbeitet von: LHerzog um 8:57 AM (GMT -8) am 13 Jan 2022]

Top Replies

Parents Reply Children
No Data