Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Filebeat install hook failed due to leadership release error #100

Open
Sponge-Bas opened this issue Oct 3, 2022 · 0 comments
Open

Filebeat install hook failed due to leadership release error #100

Sponge-Bas opened this issue Oct 3, 2022 · 0 comments

Comments

@Sponge-Bas
Copy link

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 "<root>=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: "<root>=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 <nil>}
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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant