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.
Thanks for your reply RichardP
I worry about that issue because it seems to be reproducable and as soon as an Admin logs on to the machine via RDP, I can see the 8001 MCS Error in Eventlog.
Then, before…
The 503 errors are the backend telling the clients it can't process the request. These sometimes happen if the connection attempts saturate the servers. Our product automatically backs off for a random time and then reattempts the connection. You can see the successful 200 return later in the log - this means the issue is not persistent and nothing to worry about.
It won't have anything to do with actions you are taking on the endpoint/server and because it is a 500 level error it is coming from the destination - so the issue isn't in your network unless you have a forwarding proxy - which I doubt.
I hope that answers your questions.
RichardP
Program Manager, Support Readiness | CISSP | Sophos Technical SupportSupport Videos | Product Documentation | @SophosSupport | Sign up for SMS AlertsIf a post solves your question use the 'Verify Answer' link.
Then, before the admin logs on, the machine is selectable in Central for Live Discover, after the logon, the Server disappears from the list here:
new SDU with
sdu-feedback.sophos.com/.../f90ff178-b4db-4b1e-90b2-e63fdc78fe54_2022-01-13-08-49-30.zip
The last days I monitored this on multiple machines. Today I tried to reproduce and could'nt. As written initially: "We've this occasionally on Windows hosts". Will see, what next week brings.