I'm on 7.14 with 7.14 stack an have an Elastic Agent enrolled and then run it. The policy is the default policy created by Fleet. I start up the Elastic Agent and after it is healthy I stop it (Ctrl-C). The stopping of the Elastic Agent takes a long time. In the below example I stopped the Elastic Agent at 2021-08-20T13:09:37 and it fully shut down at 2021-08-20T13:11:08 which is ~90s later. If no output is blocking which I don't think is the case here I would expect Elastic Agent to shut down much faster. It should be investigated what is blocking the shut down and why it takes so long.
Logs from Elastic Agent.
sudo ./elastic-agent run -e
2021-08-20T13:08:38.927+0200 INFO application/application.go:66 Detecting execution mode
2021-08-20T13:08:38.931+0200 INFO application/application.go:91 Agent is managed by Fleet
2021-08-20T13:08:38.931+0200 INFO capabilities/capabilities.go:59 capabilities file not found in /Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/capabilities.yml
2021-08-20T13:08:39.345+0200 INFO [api] api/server.go:62 Starting stats endpoint
2021-08-20T13:08:39.346+0200 INFO application/managed_mode.go:291 Agent is starting
2021-08-20T13:08:39.347+0200 INFO [api] api/server.go:64 Metrics endpoint listening on: /Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/data/tmp/elastic-agent.sock (configured: unix:///Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/data/tmp/elastic-agent.sock)
2021-08-20T13:08:39.448+0200 WARN application/managed_mode.go:304 failed to ack update open /Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/data/.update-marker: no such file or directory
2021-08-20T13:08:42.503+0200 INFO stateresolver/stateresolver.go:48 New State ID is NoJg31Qg
2021-08-20T13:08:42.503+0200 INFO stateresolver/stateresolver.go:49 Converging state requires execution of 3 step(s)
2021-08-20T13:09:04.557+0200 INFO log/reporter.go:40 2021-08-20T13:09:04+02:00 - message: Application: filebeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STARTING: Starting - type: 'STATE' - sub_type: 'STARTING'
2021-08-20T13:09:07.845+0200 INFO log/reporter.go:40 2021-08-20T13:09:07+02:00 - message: Application: filebeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to RUNNING: Running - type: 'STATE' - sub_type: 'RUNNING'
2021-08-20T13:09:11.730+0200 INFO log/reporter.go:40 2021-08-20T13:09:11+02:00 - message: Application: metricbeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STARTING: Starting - type: 'STATE' - sub_type: 'STARTING'
2021-08-20T13:09:11.911+0200 INFO operation/operator.go:259 operation 'operation-install' skipped for filebeat.7.14.0
2021-08-20T13:09:12.104+0200 INFO log/reporter.go:40 2021-08-20T13:09:12+02:00 - message: Application: filebeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STARTING: Starting - type: 'STATE' - sub_type: 'STARTING'
2021-08-20T13:09:12.268+0200 INFO operation/operator.go:259 operation 'operation-install' skipped for metricbeat.7.14.0
2021-08-20T13:09:12.398+0200 INFO log/reporter.go:40 2021-08-20T13:09:12+02:00 - message: Application: metricbeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STARTING: Starting - type: 'STATE' - sub_type: 'STARTING'
2021-08-20T13:09:12.404+0200 INFO stateresolver/stateresolver.go:66 Updating internal state
2021-08-20T13:09:13.383+0200 INFO log/reporter.go:40 2021-08-20T13:09:13+02:00 - message: Application: filebeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to RUNNING: Running - type: 'STATE' - sub_type: 'RUNNING'
2021-08-20T13:09:14.525+0200 INFO log/reporter.go:40 2021-08-20T13:09:14+02:00 - message: Application: metricbeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to RUNNING: Running - type: 'STATE' - sub_type: 'RUNNING'
2021-08-20T13:09:14.538+0200 INFO log/reporter.go:40 2021-08-20T13:09:14+02:00 - message: Application: metricbeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to RUNNING: Running - type: 'STATE' - sub_type: 'RUNNING'
^C2021-08-20T13:09:37.537+0200 INFO cmd/run.go:189 Shutting down Elastic Agent and sending last events...
2021-08-20T13:09:37.537+0200 INFO operation/operator.go:191 waiting for installer of pipeline 'default' to finish
2021-08-20T13:09:37.538+0200 INFO process/app.go:181 Signaling application to stop because of shutdown: filebeat--7.14.0--36643631373035623733363936343635
2021-08-20T13:09:37.539+0200 ERROR fleet/fleet_gateway.go:205 Could not communicate with fleet-server Checking API will retry, error: fail to checkin to fleet-server: Post "https://842d2a3cdf39e9ae2e0b2c7ca7cea075.fleet.us-east-1.aws.found.io:443/api/fleet/agents/3d8c3a0d-234f-4db4-a1c9-9008b7a159b2/checkin?": context canceled
2021-08-20T13:09:38.043+0200 INFO process/app.go:181 Signaling application to stop because of shutdown: metricbeat--7.14.0--36643631373035623733363936343635
2021-08-20T13:09:38.043+0200 INFO log/reporter.go:40 2021-08-20T13:09:38+02:00 - message: Application: filebeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STOPPED: Stopped - type: 'STATE' - sub_type: 'STOPPED'
2021-08-20T13:10:08.222+0200 INFO process/app.go:181 Signaling application to stop because of shutdown: filebeat--7.14.0
2021-08-20T13:10:08.222+0200 INFO log/reporter.go:40 2021-08-20T13:10:08+02:00 - message: Application: metricbeat--7.14.0--36643631373035623733363936343635[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STOPPED: Stopped - type: 'STATE' - sub_type: 'STOPPED'
2021-08-20T13:10:09.107+0200 INFO log/reporter.go:40 2021-08-20T13:10:09+02:00 - message: Application: filebeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to DEGRADED: Missed last check-in - type: 'STATE' - sub_type: 'RUNNING'
2021-08-20T13:10:09.107+0200 WARN status/reporter.go:236 Elastic Agent status changed to: 'degraded'
2021-08-20T13:10:19.113+0200 INFO log/reporter.go:40 2021-08-20T13:10:19+02:00 - message: Application: metricbeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to DEGRADED: Missed last check-in - type: 'STATE' - sub_type: 'RUNNING'
2021-08-20T13:10:38.388+0200 INFO process/app.go:181 Signaling application to stop because of shutdown: metricbeat--7.14.0
2021-08-20T13:10:38.388+0200 INFO log/reporter.go:40 2021-08-20T13:10:38+02:00 - message: Application: filebeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STOPPED: Stopped - type: 'STATE' - sub_type: 'STOPPED'
2021-08-20T13:10:53.762+0200 ERROR fleet/fleet_gateway.go:167 context canceled
2021-08-20T13:10:53.762+0200 ERROR status/reporter.go:236 Elastic Agent status changed to: 'error'
2021-08-20T13:10:55.076+0200 INFO fleet/fleet_gateway.go:299 Fleet gateway is stopping
2021-08-20T13:10:55.076+0200 WARN status/reporter.go:236 Elastic Agent status changed to: 'degraded'
2021-08-20T13:11:08.559+0200 INFO status/reporter.go:236 Elastic Agent status changed to: 'online'
2021-08-20T13:11:08.560+0200 INFO log/reporter.go:40 2021-08-20T13:11:08+02:00 - message: Application: metricbeat--7.14.0[3d8c3a0d-234f-4db4-a1c9-9008b7a159b2]: State changed to STOPPED: Stopped - type: 'STATE' - sub_type: 'STOPPED'
2021-08-20T13:11:08.560+0200 INFO application/managed_mode.go:320 Agent is stopped
2021-08-20T13:11:08.561+0200 INFO cmd/run.go:197 Shutting down completed.
2021-08-20T13:11:08.562+0200 INFO [api] api/server.go:66 Stats endpoint (/Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/data/tmp/elastic-agent.sock) finished: accept unix /Users/ruflin/Downloads/elastic-agent-7.14.0-darwin-x86_64/data/tmp/elastic-agent.sock: use of closed network connection
In addition all the logs from the processes run by Elastic Agent logs.zip
Note: Ignore the older log files, I did run this agent once before.
I'm on 7.14 with 7.14 stack an have an Elastic Agent enrolled and then run it. The policy is the default policy created by Fleet. I start up the Elastic Agent and after it is healthy I stop it (Ctrl-C). The stopping of the Elastic Agent takes a long time. In the below example I stopped the Elastic Agent at
2021-08-20T13:09:37and it fully shut down at2021-08-20T13:11:08which is ~90s later. If no output is blocking which I don't think is the case here I would expect Elastic Agent to shut down much faster. It should be investigated what is blocking the shut down and why it takes so long.Logs from Elastic Agent.
In addition all the logs from the processes run by Elastic Agent logs.zip
Note: Ignore the older log files, I did run this agent once before.