canonical / canonical/layer-filebeat
Filebeat install hook failed due to leadership release error
- Dominant language
- Python
- Stars
- 2
- Forks
- 26
- PR merge metrics
- No merged PRs in 30d
Description
In testrun https://solutions.qa.canonical.com/v2/testruns/83677df7-6b83-4c12-97f6-629d4e898e23/, filebeat fails with:
```
App Version Status Scale Charm Channel Rev Exposed Message
apache2 active 1 apache2 stable 38 yes Unit is ready
canonical-livepatch waiting 7/8 canonical-livepatch stable 48 no agent initializing
elasticsearch 6.8.23 active 3 elasticsearch latest/candidate 66 no Ready
filebeat 6.8.23 error 8 filebeat stable 38 no hook failed: "install"
grafana active 1 grafana stable 56 yes Ready
graylog blocked 1 graylog stable 55 no Waiting for /var/snap/graylog/common/server.conf
mongodb-graylog 3.6.8 active 1 mongodb stable 75 no Unit is ready
ntp 3.5 maintenance 8 ntp stable 50 no installing charm software
prometheus active 1 prometheus2 stable 30 no Ready
telegraf waiting 7/8 telegraf stable 54 no agent initializing
Unit Workload Agent Machine Public address Ports Message
apache2/0* active idle 0 107.22.11.52 Unit is ready
canonical-livepatch/2 active idle 107.22.11.52 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/2 waiting idle 107.22.11.52 Waiting for: elasticsearch, logstash or kafka.
ntp/2 active idle 107.22.11.52 123/udp chrony: Ready
telegraf/2 active idle 107.22.11.52 9103/tcp Monitoring apache2/0 (source version/commit 76901fd)
elasticsearch/0 active executing 1 18.209.111.214 9200/tcp Ready
canonical-livepatch/3 active executing 18.209.111.214 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/3 waiting executing 18.209.111.214 Waiting for: elasticsearch, logstash or kafka.
ntp/3 active executing 18.209.111.214 123/udp chrony: Ready
telegraf/3 active executing 18.209.111.214 9103/tcp Monitoring elasticsearch/0 (source version/commit 76901fd)
elasticsearch/1 active executing 2 34.226.200.137 9200/tcp Ready
canonical-livepatch/5 active executing 34.226.200.137 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/5 waiting executing 34.226.200.137 Waiting for: elasticsearch, logstash or kafka.
ntp/5 active executing 34.226.200.137 123/udp chrony: Ready
telegraf/5 active executing 34.226.200.137 9103/tcp Monitoring elasticsearch/1 (source version/commit 76901fd)
elasticsearch/2* active executing 3 54.234.202.223 9200/tcp Ready
canonical-livepatch/0* active executing 54.234.202.223 (config-changed) Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/0* waiting executing 54.234.202.223 Waiting for: elasticsearch, logstash or kafka.
ntp/0* active executing 54.234.202.223 123/udp (leader-elected) chrony: Ready
telegraf/0* active executing 54.234.202.223 9103/tcp (leader-elected) Monitoring elasticsearch/2 (source version/commit 76901fd)
grafana/0* active idle 4 54.211.196.101 3000/tcp Ready
canonical-livepatch/6 active idle 54.211.196.101 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/6 waiting idle 54.211.196.101 Waiting for: elasticsearch, logstash or kafka.
ntp/6 active idle 54.211.196.101 123/udp chrony: Ready
telegraf/6 active idle 54.211.196.101 9103/tcp Monitoring grafana/0 (source version/commit 76901fd)
graylog/0* blocked executing 5 54.196.122.9 Waiting for /var/snap/graylog/common/server.conf
canonical-livepatch/1 waiting allocating 54.196.122.9 agent initializing
filebeat/1 error idle 54.196.122.9 hook failed: "install"
ntp/1 maintenance executing 54.196.122.9 (install) installing charm software
telegraf/1 waiting allocating 54.196.122.9 agent initializing
mongodb-graylog/0* active idle 6 18.215.231.47 27017/tcp,27019/tcp,27021/tcp,28017/tcp Unit is ready
canonical-livepatch/4 active idle 18.215.231.47 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/4 waiting idle 18.215.231.47 Waiting for: elasticsearch, logstash or kafka.
ntp/4 active idle 18.215.231.47 123/udp chrony: Ready
telegraf/4 active idle 18.215.231.47 9103/tcp Monitoring mongodb-graylog/0 (source version/commit 76901fd)
prometheus/0* active executing 7 34.238.166.68 9090/tcp,12321/tcp Ready
canonical-livepatch/7 active idle 34.238.166.68 Running kernel 5.15.0-1020.24~20.04.1-aws, patchState: nothing-to-apply (source version/commit dad6199)
filebeat/7 waiting idle 34.238.166.68 Waiting for: elasticsearch, logstash or kafka.
ntp/7 active executing 34.238.166.68 123/udp chrony: Ready
telegraf/7 active idle 34.238.166.68 9103/tcp Monitoring prometheus/0 (source version/commit 76901fd)
```
In the filebeat logs we see:
```
022-09-30 16:39:18 ERROR juju.worker.dependency engine.go:693 "migration-inactive-flag" manifold worker returned unexpected error: watcher has been stopped (stopped)
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "api-address-updater" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "hook-retry-strategy" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "meter-status" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "migration-minion" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "metric-sender" manifold worker stopped: could not send metrics: write tcp 172.31.45.58:59776->54.89.125.252:17070: write: broken pipe
stack trace:
write tcp 172.31.45.58:59776->54.89.125.252:17070: write: broken pipe
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
github.com/juju/juju/api/agent/metricsadder.(*Client).AddMetricBatches:39:
github.com/juju/juju/worker/metrics/sender.(*sender).sendMetrics:71: could not send metrics
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "logging-config-updater" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "uniter" manifold worker stopped: watcher has been stopped (stopped)
stack trace:
watcher has been stopped (stopped)
github.com/juju/juju/rpc.(*Conn).Call:178:
github.com/juju/juju/api.(*state).APICall:1252:
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "api-caller" manifold worker stopped: api connection broken unexpectedly
stack trace:
github.com/juju/juju/worker/apicaller.(*apiConnWorker).loop:75: api connection broken unexpectedly
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "leadership-tracker" manifold worker stopped: error while filebeat/1 waiting for filebeat leadership release: error blocking on leadership release: waiting for leadership cancelled by client
stack trace:
waiting for leadership cancelled by client
github.com/juju/juju/api/agent/leadership.(*client).BlockUntilLeadershipReleased:57: error blocking on leadership release
github.com/juju/juju/worker/leadership.(*Tracker).loop:140: error while filebeat/1 waiting for filebeat leadership release
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:601 "charm-dir" manifold worker completed successfully
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:601 "metric-spool" manifold worker completed successfully
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:601 "agent" manifold worker completed successfully
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:601 "api-config-watcher" manifold worker completed successfully
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:601 "migration-fortress" manifold worker completed successfully
2022-09-30 16:39:19 DEBUG juju.worker.dependency engine.go:616 "metric-collect" manifold worker stopped: fortress worker shutting down
stack trace:
github.com/juju/juju/worker/fortress.init:46: fortress worker shutting down
github.com/juju/juju/worker/metrics/collect.newCollect:165:
github.com/juju/juju/worker/fortress.Occupy:63:
github.com/juju/juju/cmd/jujud/agent/engine.occupyStart.func1:93:
2022-09-30 16:39:32 INFO juju unit_agent.go:289 Starting unit workers for "filebeat/1"
2022-09-30 16:39:32 INFO juju.agent.setup agentconf.go:128 setting logging config to "=DEBUG"
2022-09-30 16:39:32 DEBUG juju.worker.dependency engine.go:578 "migration-fortress" manifold worker started at 2022-09-30 16:39:32.621888387 +0000 UTC
2022-09-30 16:39:32 DEBUG juju.worker.dependency engine.go:578 "agent" manifold worker started at 2022-09-30 16:39:32.701932142 +0000 UTC
2022-09-30 16:39:32 DEBUG juju.worker.apicaller connect.go:116 connecting with current password
2022-09-30 16:39:32 DEBUG juju.worker.dependency engine.go:578 "api-config-watcher" manifold worker started at 2022-09-30 16:39:32.751252173 +0000 UTC
2022-09-30 16:39:32 INFO juju.worker.apicaller connect.go:163 [837e70] "unit-filebeat-1" successfully connected to "172.31.35.212:17070"
2022-09-30 16:39:32 DEBUG juju.worker.dependency engine.go:601 "api-caller" manifold worker completed successfully
2022-09-30 16:39:32 DEBUG juju.worker.apicaller connect.go:116 connecting with current password
2022-09-30 16:39:33 INFO juju.worker.apicaller connect.go:163 [837e70] "unit-filebeat-1" successfully connected to "172.31.35.212:17070"
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "api-caller" manifold worker started at 2022-09-30 16:39:33.856848903 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "migration-minion" manifold worker started at 2022-09-30 16:39:33.884984235 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "upgrader" manifold worker started at 2022-09-30 16:39:33.885016299 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "log-sender" manifold worker started at 2022-09-30 16:39:33.927280084 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "migration-inactive-flag" manifold worker started at 2022-09-30 16:39:33.927877958 +0000 UTC
2022-09-30 16:39:33 INFO juju.worker.upgrader upgrader.go:216 no waiter, upgrader is done
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:601 "upgrader" manifold worker completed successfully
2022-09-30 16:39:33 INFO juju.worker.migrationminion worker.go:142 migration phase is now: NONE
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "charm-dir" manifold worker started at 2022-09-30 16:39:33.970017045 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:578 "leadership-tracker" manifold worker started at 2022-09-30 16:39:33.9897198 +0000 UTC
2022-09-30 16:39:33 DEBUG juju.worker.dependency engine.go:616 "uniter" manifold worker stopped: fortress operation aborted
stack trace:
github.com/juju/juju/worker/fortress.init:43: fortress operation aborted
github.com/juju/juju/worker/fortress.Occupy:60:
github.com/juju/juju/cmd/jujud/agent/engine.occupyStart.func1:93:
2022-09-30 16:39:34 DEBUG juju.worker.logger logger.go:65 initial log config: "=DEBUG"
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "meter-status" manifold worker started at 2022-09-30 16:39:34.016533042 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "logging-config-updater" manifold worker started at 2022-09-30 16:39:34.017338912 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "metric-spool" manifold worker started at 2022-09-30 16:39:34.017386432 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "api-address-updater" manifold worker started at 2022-09-30 16:39:34.017412352 +0000 UTC
2022-09-30 16:39:34 INFO juju.worker.logger logger.go:120 logger worker started
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "metric-sender" manifold worker started at 2022-09-30 16:39:34.032952372 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "hook-retry-strategy" manifold worker started at 2022-09-30 16:39:34.063946794 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.dependency engine.go:578 "uniter" manifold worker started at 2022-09-30 16:39:34.077804923 +0000 UTC
2022-09-30 16:39:34 DEBUG juju.worker.meterstatus connected.go:93 got meter status change signal from watcher
2022-09-30 16:39:34 DEBUG juju.worker.apiaddressupdater apiaddressupdater.go:98 updating API hostPorts to [[54.89.125.252:17070 172.31.35.212:17070 252.35.212.1:17070 127.0.0.1:17070 [::1]:17070]]
2022-09-30 16:39:34 DEBUG juju.worker.uniter uniter.go:861 starting local juju-run listener on {unix /var/lib/juju/agents/unit-filebeat-1/run.socket }
2022-09-30 16:39:34 INFO juju.worker.uniter uniter.go:326 unit "filebeat/1" started
2022-09-30 16:39:34 DEBUG juju.worker.uniter runlistener.go:118 juju-run listener running
2022-09-30 16:39:34 INFO juju.worker.uniter uniter.go:344 hooks are retried false
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:542 got config change for filebeat/1: ok=true, hashes=[7bada25b3b7bce60653c60b1b5b5219bfb35a6aaa649181c01637529dae50c65]
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:585 got leader settings change for filebeat/1: ok=true
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:613 got storage change for filebeat/1: [] ok=true
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:553 got trust config change for filebeat/1: ok=true, hashes=[cde2d13be63a27ac5166299850945c23acd05d965470821209d775f0eca354cb]
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:603 got relations change for filebeat/1: ok=true
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:595 got action change for filebeat/1: [] ok=true
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:574 got address change for filebeat/1: ok=true, hashes=[4ad79093164db91b3dbefb3de07ab171f5b1746c48d0e91208fd0edc7b263c57]
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:489 got unit change for filebeat/1
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:623 got update status interval change for filebeat/1: ok=true
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:499 got application change for filebeat/1
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:564 got upgrade series change
2022-09-30 16:39:34 DEBUG juju.worker.uniter.remotestate watcher.go:714 no upgrade series in progress, reinitializing local upgrade series state
2022-09-30 16:39:34 INFO juju.worker.uniter resolver.go:145 awaiting error resolution for "install" hook
2022-09-30 16:39:34 DEBUG juju.worker.uniter agent.go:20 [AGENT-STATUS] error: hook failed: "install"
```
I'm not sure what actually happened here. It could be a hickup in networking that caused some failures.
Crashdumps and logs can be found here:
https://oil-jenkins.canonical.com/artifacts/83677df7-6b83-4c12-97f6-629d4e898e23/index.html
Contributor guide
Research direction
Start with testrun 83677df7-6b83-4c12-97f6-629d4e898e23 and the filebeat/1 install-hook failure. Review the supplied Filebeat logs around the leadership release error and compare the unit's state with the other Filebeat units. Done means the install hook completes without the leadership-release failure and filebeat/1 no longer reports an error.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- devops
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100