Agent gets unhealthy on assigning from policy with Elastic Defend integration to without Defend integration. #3617

amolnater-qasource · 2023-10-17T09:23:39Z

Kibana Build details:

VERSION: 8.11.0 BC2
BUILD: 67841
COMMIT: 636a8339cfad92998a5a5adb7be81e3546525ebf

Host OS: All

Preconditions:

8.11.0 BC2 Kibana cloud environment should be available.
Windows agent should be installed using System and Elastic Defend integration.

Steps to reproduce:

Navigate to Fleet>Agents tab.
Assign the agent to the policy without Elastic Defend integration.
Observe agent gets unhealthy.

Screen Recording:

Agents.-.Fleet.-.Elastic.-.Google.Chrome.2023-10-17.14-45-43.mp4

Agents.-.Fleet.-.Elastic.-.Google.Chrome.2023-10-17.14-47-06.mp4

Agent Logs:
elastic-agent-diagnostics-2023-10-17T09-17-18Z-00.zip

Agent JSON:
ec2amaz-auvpg7n-agent-details.zip

Expected Result:
Agent shouldn't get unhealthy on assigning from policy with Elastic Defend integration to without Defend integration.

Impacted Testcase:
https://elastic.testrail.io/index.php?/tests/view/2166951

Similar issue:
#3507

The text was updated successfully, but these errors were encountered:

elasticmachine · 2023-10-17T09:23:42Z

Pinging @elastic/elastic-agent-control-plane (Team:Elastic-Agent-Control-Plane)

amolnater-qasource · 2023-10-17T09:23:52Z

@manishgupta-qasource Please review.

manishgupta-qasource · 2023-10-17T09:35:20Z

Secondary review for this ticket is Done

cmacknz · 2023-10-17T17:36:07Z

"components": [
    {
      "id": "log-default",
      "type": "log",
      "status": "HEALTHY",
      "message": "Healthy: communicating with pid '128'",
      "units": [
        {
          "id": "log-default",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        },
        {
          "id": "log-default-logfile-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a",
          "type": "input",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    },
    {
      "id": "winlog-default",
      "type": "winlog",
      "status": "DEGRADED",
      "message": "Degraded: pid '4900' missed 1 check-in",
      "units": [
        {
          "id": "winlog-default-winlog-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a",
          "type": "input",
          "status": "HEALTHY",
          "message": "Healthy"
        },
        {
          "id": "winlog-default",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    },
    {
      "id": "system/metrics-default",
      "type": "system/metrics",
      "status": "HEALTHY",
      "message": "Healthy: communicating with pid '916'",
      "units": [
        {
          "id": "system/metrics-default",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        },
        {
          "id": "system/metrics-default-system/metrics-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a",
          "type": "input",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    },
    {
      "id": "filestream-monitoring",
      "type": "filestream",
      "status": "DEGRADED",
      "message": "Degraded: pid '7040' missed 1 check-in",
      "units": [
        {
          "id": "filestream-monitoring-filestream-monitoring-agent",
          "type": "input",
          "status": "HEALTHY",
          "message": "Healthy"
        },
        {
          "id": "filestream-monitoring",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    },
    {
      "id": "beat/metrics-monitoring",
      "type": "beat/metrics",
      "status": "HEALTHY",
      "message": "Healthy: communicating with pid '1552'",
      "units": [
        {
          "id": "beat/metrics-monitoring-metrics-monitoring-beats",
          "type": "input",
          "status": "CONFIGURING",
          "message": "Configuring"
        },
        {
          "id": "beat/metrics-monitoring",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    },
    {
      "id": "http/metrics-monitoring",
      "type": "http/metrics",
      "status": "DEGRADED",
      "message": "Degraded: pid '6044' missed 1 check-in",
      "units": [
        {
          "id": "http/metrics-monitoring-metrics-monitoring-agent",
          "type": "input",
          "status": "CONFIGURING",
          "message": "Configuring"
        },
        {
          "id": "http/metrics-monitoring",
          "type": "output",
          "status": "HEALTHY",
          "message": "Healthy"
        }
      ]
    }
  ],

The diagnostics shows everything is healthy but the snapshot of the agent details while this was happening shows that multiple processes are missing check ins.

cmacknz · 2023-10-17T17:36:42Z

Usually missed check ins happen due to increased CPU usage on the machine. The policy reassignment would have caused every input in the policy to stop and restart, and the missed checkins correlate with that event in the logs:

"log.level":"debug","@timestamp":"2023-10-17T09:16:42.412Z","log.logger":"component.runtime.endpoint-default.service_runtime","log.origin":{"file.name":"runtime/service.go","file.line":192},"message":"context is done. exiting.","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8 (STOPPED->STOPPING): Stopping","log":{"source":"elastic-agent"},"component":{"id":"log-default","state":"HEALTHY"},"unit":{"id":"log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPING","old_state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed beat/metrics-monitoring-metrics-monitoring-beats (CONFIGURING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"beat/metrics-monitoring","state":"HEALTHY"},"unit":{"id":"beat/metrics-monitoring-metrics-monitoring-beats","type":"input","state":"HEALTHY","old_state":"CONFIGURING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed http/metrics-monitoring-metrics-monitoring-agent (CONFIGURING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"http/metrics-monitoring","state":"HEALTHY"},"unit":{"id":"http/metrics-monitoring-metrics-monitoring-agent","type":"input","state":"HEALTHY","old_state":"CONFIGURING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed filestream-monitoring-filestream-monitoring-agent (CONFIGURING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"filestream-monitoring","state":"HEALTHY"},"unit":{"id":"filestream-monitoring-filestream-monitoring-agent","type":"input","state":"HEALTHY","old_state":"CONFIGURING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8 (STOPPING->STOPPED): Stopped","log":{"source":"elastic-agent"},"component":{"id":"winlog-default","state":"HEALTHY"},"unit":{"id":"winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED","old_state":"STOPPING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed winlog-default-winlog-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a (STARTING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"winlog-default","state":"HEALTHY"},"unit":{"id":"winlog-default-winlog-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a","type":"input","state":"HEALTHY","old_state":"STARTING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8 (STOPPING->STOPPED): Stopped","log":{"source":"elastic-agent"},"component":{"id":"system/metrics-default","state":"HEALTHY"},"unit":{"id":"system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED","old_state":"STOPPING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed system/metrics-default-system/metrics-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a (STARTING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"system/metrics-default","state":"HEALTHY"},"unit":{"id":"system/metrics-default-system/metrics-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a","type":"input","state":"HEALTHY","old_state":"STARTING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8 (STOPPING->STOPPED): Stopped","log":{"source":"elastic-agent"},"component":{"id":"log-default","state":"HEALTHY"},"unit":{"id":"log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED","old_state":"STOPPING"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":558},"message":"Unit state changed log-default-logfile-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a (STARTING->HEALTHY): Healthy","log":{"source":"elastic-agent"},"component":{"id":"log-default","state":"HEALTHY"},"unit":{"id":"log-default-logfile-system-0a5c1691-2ce5-4a4f-8ead-f5b1e767f61a","type":"input","state":"HEALTHY","old_state":"STARTING"},"ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":540},"message":"Component state changed filestream-monitoring (HEALTHY->DEGRADED): Degraded: pid '7040' missed 1 check-in","log":{"source":"elastic-agent"},"component":{"id":"filestream-monitoring","state":"DEGRADED","old_state":"HEALTHY"},"ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":540},"message":"Component state changed http/metrics-monitoring (HEALTHY->DEGRADED): Degraded: pid '6044' missed 1 check-in","log":{"source":"elastic-agent"},"component":{"id":"http/metrics-monitoring","state":"DEGRADED","old_state":"HEALTHY"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"system/metrics-default","state":"HEALTHY"},"unit":{"id":"system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"log-default","state":"HEALTHY"},"unit":{"id":"log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":540},"message":"Component state changed winlog-default (HEALTHY->DEGRADED): Degraded: pid '4900' missed 1 check-in","log":{"source":"elastic-agent"},"component":{"id":"winlog-default","state":"DEGRADED","old_state":"HEALTHY"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"log-default","state":"HEALTHY"},"unit":{"id":"log-default-logfile-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"winlog-default","state":"DEGRADED"},"unit":{"id":"winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"system/metrics-default","state":"HEALTHY"},"unit":{"id":"system/metrics-default-system/metrics-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-10-17T09:16:42.412Z","log.origin":{"file.name":"coordinator/coordinator.go","file.line":550},"message":"Spawned new unit winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8: Stopped","log":{"source":"elastic-agent"},"component":{"id":"winlog-default","state":"DEGRADED"},"unit":{"id":"winlog-default-winlog-system-255f7854-c0d1-46f4-b861-021bac628fd8","type":"input","state":"STOPPED"},"ecs.version":"1.6.0"}

cmacknz · 2023-10-17T17:37:40Z

Does this happen every time? If it does happen every time can it be reproduced on the latest 8.10.4 release? Are you able to check or record the CPU usage of the machine running the agent when the policy reassignment is happening?

amolnater-qasource · 2023-10-19T05:35:22Z

Hi @cmacknz

Thank you for looking into this.

We have validated this issue on 8.10.4 released production environment and found it not reproducible there.
We have also revalidated this issue on 8.11.0 BC3 kibana cloud environment and found it consistently reproducible there.

Further observations:

CPU consumption reaches 100% on reassigning the policy on both the kibana versions- 8.10.4 and 8.11.0.
However, only 8.11.0 agent gets unhealthy on reassigning and 8.10.4 agent remains Unhealthy.

Screen Recordings:
8.10.4:

Agents.-.Fleet.-.Elastic.-.Google.Chrome.2023-10-19.10-28-25.mp4

Amol.Windows.-.ec2-18-212-196-2.compute-1.amazonaws.com.-.Remote.Desktop.Connection.2023-10-19.10-28-57.mp4

8.11.0:

Amol.Windows.-.ec2-18-212-196-2.compute-1.amazonaws.com.-.Remote.Desktop.Connection.2023-10-19.10-46-29.mp4

Agents.-.Fleet.-.Elastic.-.Google.Chrome.2023-10-19.10-47-19.mp4

Please let us know if anything else is required from our end.

Thanks!!

cmacknz · 2023-10-23T19:37:53Z

When the CPU reaches 100%, can you run elastic-agent diagnostics --cpu-profile and attach the results here?

amolnater-qasource · 2023-10-25T11:44:22Z

Hi @cmacknz

We have reproduced this issue and recollected the new logs when CPU reached 100% with the shared command.

Logs:
elastic-agent-diagnostics-2023-10-25T11-34-54Z-00.zip

Please let us know if anything else is required from our end.

Thanks!!

cmacknz · 2023-10-25T21:01:24Z

The latest diagnostics isn't giving me any clues but likely this is the same problem as #3654

cmacknz · 2023-10-26T13:42:48Z

Pulling this into the sprint and assigning to Lee since this is the same as #3654 but we'll need to retest this scenario to confirm.

amolnater-qasource · 2024-01-11T08:46:30Z

Hi Team,

We have revalidated this issue on latest 8.12.0 BC5 kibana cloud environment and found it fixed now.

Observations:

Agent remains healthy on assigning from policy with Elastic Defend integration to without Defend integration.
Issue is also not reproducible if the agent tamper protections are also enabled.

Build details:
VERSION: 8.12.0 BC5
BUILD: 70053
COMMIT: db9b8921b37139cbb1e11d23f6381f655edeb72b
Artifact Link: https://staging.elastic.co/8.12.0-9f05a310/summary-8.12.0.html

Screenshot:

Hence we are marking this issue as QA:Validated.

Thanks!

harshitgupta-qasource · 2024-01-25T11:10:10Z

`Bug Conversion:`

We have updated 01 testcase for this scenario in our fleet test suite at:

https://elastic.testrail.io/index.php?/cases/view/28390

Thanks

amolnater-qasource added bug Something isn't working Team:Elastic-Agent-Control-Plane Label for the Agent Control Plane team impact:high Short-term priority; add to current release, or definitely next. labels Oct 17, 2023

cmacknz mentioned this issue Oct 25, 2023

Linux agents gets unhealthy on enabling/disabling modules for System/Linux integration. #3654

Closed

cmacknz assigned leehinman Oct 26, 2023

leehinman mentioned this issue Nov 10, 2023

runtime.update can block all checkins and state processing while waiting for shutdown #3738

Closed

faec mentioned this issue Nov 15, 2023

Rework runtime manager updates to block the coordinator less #3747

Merged

7 tasks

faec closed this as completed in #3747 Nov 16, 2023

amolnater-qasource added the QA:Ready For Testing Code is merged and ready for QA to validate label Nov 19, 2023

amolnater-qasource added QA:Validated Validated by the QA Team and removed QA:Ready For Testing Code is merged and ready for QA to validate labels Jan 11, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Agent gets unhealthy on assigning from policy with Elastic Defend integration to without Defend integration. #3617

Agent gets unhealthy on assigning from policy with Elastic Defend integration to without Defend integration. #3617

amolnater-qasource commented Oct 17, 2023

elasticmachine commented Oct 17, 2023

amolnater-qasource commented Oct 17, 2023

manishgupta-qasource commented Oct 17, 2023

cmacknz commented Oct 17, 2023

cmacknz commented Oct 17, 2023

cmacknz commented Oct 17, 2023

amolnater-qasource commented Oct 19, 2023

cmacknz commented Oct 23, 2023

amolnater-qasource commented Oct 25, 2023

cmacknz commented Oct 25, 2023

cmacknz commented Oct 26, 2023

amolnater-qasource commented Jan 11, 2024

harshitgupta-qasource commented Jan 25, 2024

Agent gets unhealthy on assigning from policy with Elastic Defend integration to without Defend integration. #3617

Agent gets unhealthy on assigning from policy with Elastic Defend integration to without Defend integration. #3617

Comments

amolnater-qasource commented Oct 17, 2023

elasticmachine commented Oct 17, 2023

amolnater-qasource commented Oct 17, 2023

manishgupta-qasource commented Oct 17, 2023

cmacknz commented Oct 17, 2023

cmacknz commented Oct 17, 2023

cmacknz commented Oct 17, 2023

amolnater-qasource commented Oct 19, 2023

cmacknz commented Oct 23, 2023

amolnater-qasource commented Oct 25, 2023

cmacknz commented Oct 25, 2023

cmacknz commented Oct 26, 2023

amolnater-qasource commented Jan 11, 2024

harshitgupta-qasource commented Jan 25, 2024

Bug Conversion:

`Bug Conversion:`