leader-settings-changed hook failed, with hvac.exceptions.InvalidRequest

Bug #2062819 reported by Jeffrey Chang
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
vault-charm
New
Undecided
Unassigned

Bug Description

Running a deployment of charmed Kubernetes 1.29 with juju 3.1.8 and vault on the channel 1.7/stable , a non leader, failed on the leader-setting-changed hook during vault unseal step.
Testrun - https://solutions.qa.canonical.com/testruns/66fec8f2-f161-4352-9851-b64250392477

The juju logs from the unit show:
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 Traceback (most recent call last):
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/charm/hooks/leader-settings-changed", line 22, in <module>
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 main()
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/charms/reactive/__init__.py", line 74, in main
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 bus.dispatch(restricted=restricted_mode)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 390, in dispatch
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 _invoke(other_handlers)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 359, in _invoke
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 handler.invoke()
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 181, in invoke
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 self._action(*args)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/charm/reactive/vault_handlers.py", line 1054, in sync_cert_from_cache
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 ca_chain = vault_pki.get_chain()
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/charm/lib/charm/vault_pki.py", line 85, in get_chain
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 return client.read('{}/cert/ca_chain'.format(name))['data']['certificate']
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/hvac/v1/__init__.py", line 157, in read
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 return self._adapter.get('/v1/{0}'.format(path), wrap_ttl=wrap_ttl).json()
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/hvac/adapters.py", line 90, in get
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 return self.request('get', url, **kwargs)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/hvac/adapters.py", line 233, in request
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 utils.raise_for_error(response.status_code, text, errors=errors)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 File "/var/lib/juju/agents/unit-vault-0/.venv/lib/python3.8/site-packages/hvac/utils.py", line 29, in raise_for_error
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 raise exceptions.InvalidRequest(message, errors=errors)
2024-04-18 18:24:52 WARNING unit.vault/0.leader-settings-changed logger.go:60 hvac.exceptions.InvalidRequest: backend must be configured with a CA certificate/key
2024-04-18 18:24:52 DEBUG juju.worker.uniter.remotestate watcher.go:701 got leader settings change for vault/0: ok=true
2024-04-18 18:24:52 ERROR juju.worker.uniter.operation runhook.go:180 hook "leader-settings-changed" (via explicit, bespoke hook script) failed: exit status 1
2024-04-18 18:24:52 DEBUG juju.machinelock machinelock.go:206 created rotating log file "/var/log/juju/machine-lock.log" with max size 10 MB and max backups 5
2024-04-18 18:24:52 DEBUG juju.machinelock machinelock.go:190 machine lock "machine-lock" released for vault/0 uniter (run leader-settings-changed hook)
2024-04-18 18:24:52 DEBUG juju.worker.uniter.operation executor.go:118 lock released for vault/0
2024-04-18 18:24:52 INFO juju.worker.uniter resolver.go:161 awaiting error resolution for "leader-settings-changed" hook

On another non-leader vault-1 unit, I can see below logs
2024-04-18 18:24:50 INFO unit.vault/1.juju-log server.go:325 Reactive main running for hook leader-settings-changed
  15470 2024-04-18 18:24:50 ERROR unit.vault/1.juju-log server.go:325 Unable to find implementation for relation: peers of vault-ha
  15471 2024-04-18 18:24:50 DEBUG unit.vault/1.juju-log server.go:325 tracer>
  15472 tracer: set flag config.default.snapd_refresh
  15473 tracer: ++ queue handler hooks/relations/tls-certificates/provides.py:45:joined:certificates
  15474 tracer: ++ queue handler reactive/vault_handlers.py:1032:sync_cert_from_cache
  15475 tracer: ++ queue handler reactive/vault_handlers.py:263:configure_vault_mysql
  15476 tracer: ++ queue handler reactive/vault_handlers.py:310:mysql_setup
  15477 tracer: ++ queue handler reactive/vault_handlers.py:341:database_not_ready
  15478 tracer: ++ queue handler reactive/vault_handlers.py:431:cluster_connected
  15479 tracer: ++ queue handler reactive/vault_handlers.py:655:prime_assess_status

2024-04-18 18:24:52 DEBUG juju.worker.uniter.remotestate watcher.go:701 got leader settings change for vault/1: ok=true
  15591 2024-04-18 18:24:53 WARNING unit.vault/1.leader-settings-changed logger.go:60 unable to load certificate
  15592 2024-04-18 18:24:53 WARNING unit.vault/1.leader-settings-changed logger.go:60 140547519210816:error:0909006C:PEM routines:get_name:no start line:../crypto/pem/pem_lib.c:745:Expecting: TRUSTED CERTIFICATE
  15593 2024-04-18 18:24:53 DEBUG unit.vault/1.juju-log server.go:325 Couldn't process certificate: reason: Command '['openssl', 'x509', '-in', '/tmp/tmp809r04z5', '-noout', '-serial']' returned non-zero exit status 1.
  15594 2024-04-18 18:24:53 WARNING unit.vault/1.juju-log server.go:325 Certificate from cache for "kubeapi-load-balancer_0" (cn: "10.244.40.109") was not found in vault, but is in the cache. Using, but may not be valid.

Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

There's not really enough here to triage the bug. As it's ha, we'll need to logs and juju show-unit for each of the units to diagnose this issue, please.

Changed in vault-charm:
status: New → Incomplete
Revision history for this message
Jeffrey Chang (modern911) wrote :

Sorry, made some error in the initial report, and updated with more details.

description: updated
Changed in vault-charm:
status: Incomplete → New
Revision history for this message
Jeffrey Chang (modern911) wrote :

bump into one run with this problem live with a kubernetes on maas sku.
Tried "juju run vault/1 restart" and then "juju run vault/1 reload".
And juju status show vault unsealed, then I unseal and all 3 nodes are happy.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.