Sophos Central customers have reported issues preventing successful installation, live terminal and device list access issues in the EU-CENTRAL-1 region For more info refer to KBA-000041338 for the latest updates.

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 Live Query Update CPU consumption and errors

Hi,

we noticed high CPU load on some servers with IX with XDR.

Today a Domain Controller, single core machine was busy for hours starting with the installation of Sophos Live Query update. After the update itself there were process running with high cpu load like SophosOsqueryExtension.exe or SophosLiveQueryService.exe.

First attempt was at 12:20, second at 14:20

SophosOsquery.log:

Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
2021-10-15T00:51:36.257Z ---Process terminated---
I1015 02:53:33.000435 14144 interface.cpp:110] Registering extension (SophosExtension, 10046, version=3.2.1.206, sdk=4.4.0)
I1015 02:53:33.016062 11380 interface.cpp:110] Registering extension (sophosmdrextension, 25143, version=2.1.0.65, sdk=)
W1015 02:53:33.548032 2232 init.cpp:597] Error reading config: Missing config plugin
2021-10-15T10:21:30.252Z ---Process terminated---
2021-10-15T10:26:14.727Z ---Process terminated---
I1015 14:19:11.046438 6368 interface.cpp:110] Registering extension (SophosServiceExtension, 15616, version=3.2.1.206, sdk=4.4.0)
I1015 14:19:12.178261 6452 interface.cpp:110] Registering extension (sophosmdrextension, 25168, version=2.1.0.65, sdk=)
I1015 14:19:12.215044 13120 interface.cpp:110] Registering extension (SophosExtension, 14931, version=3.2.1.206, sdk=4.4.0)
I1015 14:19:36.588044 9996 interfaces.cpp:102] Failed to retrieve network statistics for interface 1
I1015 14:19:36.744299 9996 interfaces.cpp:130] Failed to retrieve physical state for interface 1
I1015 14:19:36.775547 9996 interfaces.cpp:157] Failed to retrieve DHCP and DNS information for interface 1
I1015 14:19:36.791172 9996 interfaces.cpp:102] Failed to retrieve network statistics for interface 13
I1015 14:19:38.275583 7508 scheduler.cpp:112] Executing scheduled query pack_live_query_3_sophos_ips_windows
I1015 14:20:04.570500 7508 interfaces.cpp:102] Failed to retrieve network statistics for interface 1
I1015 14:20:04.803503 7508 interfaces.cpp:130] Failed to retrieve physical state for interface 1
I1015 14:20:04.850378 7508 interfaces.cpp:157] Failed to retrieve DHCP and DNS information for interface 1
I1015 14:20:04.866004 7508 interfaces.cpp:102] Failed to retrieve network statistics for interface 13
I1015 14:20:06.350426 7508 scheduler.cpp:127] Query pack_live_query_3_sophos_ips_windows finished after: 28080 milliseconds
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

SophosOsqueryExtension.log:

Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
i 2021-10-15T00:03:03.544Z [11840:10032] - Extension socket: \\.\pipe\sophoslivequery_mb7qSDpVkY.sock [Extension.cpp:116 ExtensionRunner]
i 2021-10-15T00:03:03.545Z [11840:10032] - Extension cache entry limit: 1000 [Extension.cpp:117 ExtensionRunner]
i 2021-10-15T00:03:03.545Z [11840:10032] - Extension resource usage limit: 262144000 bytes and resource check frequency: 50 rows [Extension.cpp:120 ExtensionRunner]
i 2021-10-15T00:03:03.545Z [11840:10032] - Extension internal flag: 0 [Extension.cpp:121 ExtensionRunner]
i 2021-10-15T00:03:03.545Z [11840:10032] - Extension max JRL attempts: 10 [Extension.cpp:122 ExtensionRunner]
i 2021-10-15T00:03:03.545Z [11840:10032] - Extension JRL memory limit: 157286400 [Extension.cpp:123 ExtensionRunner]
i 2021-10-15T00:03:03.645Z [11840:10032] - SED sync comms initialized [Extension.cpp:143 ExtensionRunner]
i 2021-10-15T00:03:03.694Z [11840:10032] - Starting Extension (SophosExtension) [OsqueryExtension.cpp:94 OsquerySDK::internal::Extension::Start]
i 2021-10-15T00:03:03.732Z [11840:10032] - Registered Extension (SophosExtension, 29626) [OsqueryExtension.cpp:124 OsquerySDK::internal::Extension::Start]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension socket: \\.\pipe\sophoslivequery_U8Xeb482mq.sock [Extension.cpp:116 ExtensionRunner]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension cache entry limit: 1000 [Extension.cpp:117 ExtensionRunner]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension resource usage limit: 262144000 bytes and resource check frequency: 50 rows [Extension.cpp:120 ExtensionRunner]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension internal flag: 0 [Extension.cpp:121 ExtensionRunner]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension max JRL attempts: 10 [Extension.cpp:122 ExtensionRunner]
i 2021-10-15T00:53:32.182Z [2708:13040] - Extension JRL memory limit: 157286400 [Extension.cpp:123 ExtensionRunner]
i 2021-10-15T00:53:32.983Z [2708:13040] - SED sync comms initialized [Extension.cpp:143 ExtensionRunner]
i 2021-10-15T00:53:32.986Z [2708:13040] - Starting Extension (SophosExtension) [OsqueryExtension.cpp:94 OsquerySDK::internal::Extension::Start]
i 2021-10-15T00:53:33.054Z [2708:13040] - Registered Extension (SophosExtension, 10046) [OsqueryExtension.cpp:124 OsquerySDK::internal::Extension::Start]
i 2021-10-15T12:19:11.439Z [2544:7140] - Extension socket: \\.\pipe\sophoslivequery_MgwNX22Pmq.sock [Extension.cpp:116 ExtensionRunner]
i 2021-10-15T12:19:11.448Z [2544:7140] - Extension cache entry limit: 1000 [Extension.cpp:117 ExtensionRunner]
i 2021-10-15T12:19:11.448Z [2544:7140] - Extension resource usage limit: 262144000 bytes and resource check frequency: 50 rows [Extension.cpp:120 ExtensionRunner]
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

SophosMTRExtension.log:

Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
2021-10-15T02:03:03.556+0200 info sophos.logger logging configured {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
2021-10-15T02:03:03.640+0200 info sophos.logger default logger updated
2021-10-15T02:03:03.640+0200 info sophos Sophos MTR Extension 2.1.0.65 - Commit 4cf9e440aedc818512dbfeb5f63d3c98cc5ae4c2
2021-10-15T02:03:03.640+0200 info sophos Registering sophosmdrextension
2021-10-15T02:51:25.671+0200 error sophos server run error: extension ping failed: i/o timeout
2021-10-15T02:53:32.265+0200 info sophos.logger logging configured {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
2021-10-15T02:53:32.349+0200 info sophos.logger default logger updated
2021-10-15T02:53:32.349+0200 info sophos Sophos MTR Extension 2.1.0.65 - Commit 4cf9e440aedc818512dbfeb5f63d3c98cc5ae4c2
2021-10-15T02:53:32.349+0200 info sophos Registering sophosmdrextension
2021-10-15T14:19:11.451+0200 info sophos.logger logging configured {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
2021-10-15T14:19:12.160+0200 info sophos.logger default logger updated
2021-10-15T14:19:12.160+0200 info sophos Sophos MTR Extension 2.1.0.65 - Commit 4cf9e440aedc818512dbfeb5f63d3c98cc5ae4c2
2021-10-15T14:19:12.160+0200 info sophos Registering sophosmdrextension
2021-10-15T15:16:43.233+0200 info sophos.logger logging configured {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
2021-10-15T15:16:43.365+0200 info sophos.logger default logger updated
2021-10-15T15:16:43.365+0200 info sophos Sophos MTR Extension 2.1.0.65 - Commit 4cf9e440aedc818512dbfeb5f63d3c98cc5ae4c2
2021-10-15T15:16:43.365+0200 info sophos Registering sophosmdrextension
2021-10-15T15:34:38.148+0200 info sophos.logger logging configured {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
2021-10-15T15:34:38.233+0200 info sophos.logger default logger updated
2021-10-15T15:34:38.233+0200 info sophos Sophos MTR Extension 2.1.0.65 - Commit 4cf9e440aedc818512dbfeb5f63d3c98cc5ae4c2
2021-10-15T15:34:38.233+0200 info sophos Registering sophosmdrextension
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

Auto Update Log filtered for Query:

Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
Line 61: 2021-10-15T10:18:01.726Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.CSP_2-18-2_10-8-10-3.1: looking for packages included from product LiveQuery64 3.2.1.206 path=livequery64
Line 61: 2021-10-15T10:18:01.726Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.CSP_2-18-2_10-8-10-3.1: looking for packages included from product LiveQuery64 3.2.1.206 path=livequery64
Line 62: 2021-10-15T10:18:01.726Z [ 3240:12072] [v6.7.352.0] INFO [I22529] sdds.CSP_2-18-2_10-8-10-3.1: looking for supplements included from product LiveQuery64 3.2.1.206 path=livequery64
Line 62: 2021-10-15T10:18:01.726Z [ 3240:12072] [v6.7.352.0] INFO [I22529] sdds.CSP_2-18-2_10-8-10-3.1: looking for supplements included from product LiveQuery64 3.2.1.206 path=livequery64
Line 63: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 63: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 63: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 63: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 63: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 64: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 64: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 64: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 64: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 64: 2021-10-15T10:18:01.922Z [ 3240:12072] [v6.7.352.0] INFO [I49502] sdds.scheduled_qp.xml: found supplement ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next baseVersion= [included from product LiveQuery64 3.2.1.206 path=livequery64]
Line 111: 2021-10-15T10:18:02.861Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.scheduled_qp.xml: looking for packages included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 111: 2021-10-15T10:18:02.861Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.scheduled_qp.xml: looking for packages included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 111: 2021-10-15T10:18:02.861Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.scheduled_qp.xml: looking for packages included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 112: 2021-10-15T10:18:02.862Z [ 3240:12072] [v6.7.352.0] INFO [I22529] sdds.scheduled_qp.xml: looking for supplements included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 112: 2021-10-15T10:18:02.862Z [ 3240:12072] [v6.7.352.0] INFO [I22529] sdds.scheduled_qp.xml: looking for supplements included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 112: 2021-10-15T10:18:02.862Z [ 3240:12072] [v6.7.352.0] INFO [I22529] sdds.scheduled_qp.xml: looking for supplements included from product ScheduledQueryPack LATEST path=livequery64/scheduled_query_pack_latest
Line 113: 2021-10-15T10:18:02.862Z [ 3240:12072] [v6.7.352.0] INFO [I95020] sdds.scheduled_qp.xml: looking for packages included from product ScheduledQueryPack NEXT path=livequery64/scheduled_query_pack_next
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

SophosOsquery.log has always reocourring errors:

I1015 16:14:17.199028 11652 processes.cpp:366] Failed to lookup path information for process 4
I1015 16:14:17.199028 11652 processes.cpp:338] Failed to get PEB UPP for 4 with 0
I1015 16:14:17.199028 11652 processes.cpp:380] Failed to get cwd for 4 with 0
I1015 16:14:17.199028 11652 processes.cpp:272] Failed to get PEB UPP for 4 with 0
I1015 16:14:17.199028 11652 processes.cpp:338] Failed to get PEB UPP for 312 with 5
I1015 16:14:17.199028 11652 processes.cpp:380] Failed to get cwd for 312 with 5
I1015 16:14:17.199028 11652 processes.cpp:338] Failed to get PEB UPP for 408 with 5
I1015 16:14:17.199028 11652 processes.cpp:380] Failed to get cwd for 408 with 5
I1015 16:14:17.199028 11652 processes.cpp:338] Failed to get PEB UPP for 496 with 5
I1015 16:14:17.199028 11652 processes.cpp:380] Failed to get cwd for 496 with 5
I1015 16:14:17.199028 11652 processes.cpp:338] Failed to get PEB UPP for 592 with 5
I1015 16:14:17.199028 11652 processes.cpp:380] Failed to get cwd for 592 with 5
I1015 16:14:17.214648 11652 processes.cpp:338] Failed to get PEB UPP for 7688 with 5
I1015 16:14:17.214648 11652 processes.cpp:380] Failed to get cwd for 7688 with 5

SophosMTRExtension.log is showing this error repeatedly.

2021-10-15T15:52:53.133+0200    info    sophos    Registering sophosmdrextension
2021-10-15T15:57:04.187+0200    error    sophos    server run error: extension ping failed: i/o timeout

We're no MTR customer, why is it trying to register something with MTR all the time?



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

    Couple of questions here:

    1) are you running Live queries against this machine?

    2) have you turned on data lake hydration?

    Based on the errors in those logs - I suggest you open a support case. We will need an SDU from the machine (Endpoint UI > About > Endpoint Self Help > SDU) and a process monitor capture to see what is going on. 

    Does the activity ever die down? 

    • Hi,

      thanks for your reply. We were not running queries against that machines. Data Lake uploads is enabled.I wonder if we could somehow recreate the CPU spikes caused by the updateprocess. But except restoring a VM backup I have no idea how we could do that.

      The CPU activity went normal after that hour shown in the screenshot above.

      This is still happening all the time, causing some big logs:

      SophosOsquery.log

      I1018 10:58:16.352298  7404 scheduler.cpp:112] Executing scheduled query open_sockets
      I1018 10:58:17.492595  7404 processes.cpp:366] Failed to lookup path information for process 4
      I1018 10:58:17.492595  7404 processes.cpp:338] Failed to get PEB UPP for 4 with 0
      I1018 10:58:17.492595  7404 processes.cpp:380] Failed to get cwd for 4 with 0
      I1018 10:58:17.492595  7404 processes.cpp:272] Failed to get PEB UPP for 4 with 0
      I1018 10:58:17.492595  7404 processes.cpp:338] Failed to get PEB UPP for 312 with 5
      I1018 10:58:17.492595  7404 processes.cpp:380] Failed to get cwd for 312 with 5
      I1018 10:58:17.492595  7404 processes.cpp:338] Failed to get PEB UPP for 408 with 5
      I1018 10:58:17.492595  7404 processes.cpp:380] Failed to get cwd for 408 with 5
      I1018 10:58:17.492595  7404 processes.cpp:338] Failed to get PEB UPP for 496 with 5
      I1018 10:58:17.492595  7404 processes.cpp:380] Failed to get cwd for 496 with 5
      I1018 10:58:17.492595  7404 processes.cpp:338] Failed to get PEB UPP for 592 with 5
      I1018 10:58:17.492595  7404 processes.cpp:380] Failed to get cwd for 592 with 5
      I1018 10:58:17.555094  7404 processes.cpp:338] Failed to get PEB UPP for 9356 with 5
      I1018 10:58:17.555094  7404 processes.cpp:380] Failed to get cwd for 9356 with 5
      I1018 10:58:17.680096  7404 scheduler.cpp:127] Query open_sockets finished after: 1330 milliseconds
      I1018 10:58:23.112090  7404 scheduler.cpp:112] Executing scheduled query pack_live_query_3_running_processes_windows_sophos
      I1018 10:58:23.446413  7404 scheduler.cpp:127] Query pack_live_query_3_running_processes_windows_sophos finished after: 345 milliseconds
      I1018 10:58:45.196924  7404 scheduler.cpp:112] Executing scheduled query pack_live_query_3_changed_files_windows_sophos

      MTR is showing ping failed: i/o timeout errors sometimes but now seems to have registered though we're not MTR customer.

      SophosMTRExtension.log

      2021-10-16T18:41:13.567+0200    info    sophos    Registering sophosmdrextension
      2021-10-17T02:01:25.395+0200    info    sophos.logger    logging configured    {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
      2021-10-17T02:01:25.487+0200    info    sophos.logger    default logger updated
      2021-10-17T02:01:25.487+0200    info    sophos    Sophos MTR Extension 2.1.0.65 - Commit xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxc5ae4c2
      2021-10-17T02:01:25.487+0200    info    sophos    Registering sophosmdrextension
      2021-10-17T08:21:14.467+0200    error    sophos    server run error: extension ping failed: i/o timeout
      2021-10-17T08:21:54.913+0200    info    sophos.logger    logging configured    {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
      2021-10-17T08:21:55.015+0200    info    sophos.logger    default logger updated
      2021-10-17T08:21:55.015+0200    info    sophos    Sophos MTR Extension 2.1.0.65 - Commit xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxc5ae4c2
      2021-10-17T08:21:55.015+0200    info    sophos    Registering sophosmdrextension
      2021-10-17T18:01:47.850+0200    info    sophos.logger    logging configured    {"fileName": "C:\\ProgramData\\Sophos\\Live Query\\Logs\\SophosMTRExtension.log", "maxSizeMB": 10, "maxBackups": 3, "level": "info", "maxAgeInDays": 30}
      2021-10-17T18:01:47.935+0200    info    sophos.logger    default logger updated
      2021-10-17T18:01:47.935+0200    info    sophos    Sophos MTR Extension 2.1.0.65 - Commit xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxc5ae4c2
      2021-10-17T18:01:47.935+0200    info    sophos    Registering sophosmdrextension

      SophosOsqueryExtension.log

      seems OK for me

      • Case 04525567 for the SophosOsquery.log Failures

        Got update from support about the Failed to get PEB UPP, cwd and so on failures:

        GES confirmed: Failures are just resulting noisy errors from the open_sockets query. These are not an issue nor to they indicate and issue with the software however they addressed in our 2021.3 Central release. ...  they are nothing that could affect the security or the usability of the product.