Comment 2 for bug 1760138

Revision history for this message
Frode Nordahl (fnordahl) wrote :

This looks like a bug or race in juju itself.

2018-03-30 01:49:16 DEBUG juju.worker.dependency engine.go:486 "leadership-tracker" manifold worker started
2018-03-30 01:49:16 DEBUG juju.worker.leadership tracker.go:131 ceph-mon/1 making initial claim for ceph-mon leadership
2018-03-30 01:49:59 INFO juju.worker.leadership tracker.go:200 ceph-mon/1 promoted to leadership of ceph-mon
2018-03-30 01:54:26 DEBUG juju.worker.uniter.operation executor.go:60 running operation accept leadership
2018-03-30 01:54:26 DEBUG juju.worker.uniter.operation executor.go:91 preparing operation "accept leadership"
2018-03-30 01:54:26 DEBUG juju.worker.uniter.operation executor.go:91 committing operation "accept leadership"
2018-03-30 01:58:27 INFO juju.worker.leadership tracker.go:223 ceph-mon leadership for ceph-mon/1 denied
2018-03-30 01:58:27 DEBUG juju.worker.leadership tracker.go:237 notifying ceph-mon/1 ticket of impending loss of ceph-mon leadership
2018-03-30 01:58:27 DEBUG juju.worker.leadership tracker.go:276 ceph-mon/1 is not ceph-mon leader
2018-03-30 01:58:27 DEBUG juju.worker.leadership tracker.go:230 ceph-mon/1 waiting for ceph-mon leadership release
2018-03-30 01:58:27 DEBUG juju.worker.uniter.remotestate watcher.go:445 got leadership change for ceph-mon/1: minion

However, just before the Traceback the charm executes is-leader in the hookenv and gets a positive answer from Juju.

2018-03-30 01:58:27 DEBUG config-changed ERROR cannot write leadership settings: cannot write settings: not the leader
2018-03-30 01:58:27 DEBUG config-changed Traceback (most recent call last):
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/config-changed", line 725, in <module>
2018-03-30 01:58:27 DEBUG config-changed hooks.execute(sys.argv)
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/charmhelpers/core/hookenv.py", line 800, in execute
2018-03-30 01:58:27 DEBUG config-changed self._hooks[hook_name]()
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/charmhelpers/contrib/hardening/harden.py", line 79, in _harden_inner2
2018-03-30 01:58:27 DEBUG config-changed return f(*args, **kwargs)
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/config-changed", line 214, in config_changed
2018-03-30 01:58:27 DEBUG config-changed leader_set(opts)
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/charmhelpers/core/hookenv.py", line 929, in inner_translate_exc2
2018-03-30 01:58:27 DEBUG config-changed return f(*args, **kwargs)
2018-03-30 01:58:27 DEBUG config-changed File "/var/lib/juju/agents/unit-ceph-mon-1/charm/hooks/charmhelpers/core/hookenv.py", line 982, in leader_set
2018-03-30 01:58:27 DEBUG config-changed subprocess.check_call(cmd)
2018-03-30 01:58:27 DEBUG config-changed File "/usr/lib/python3.5/subprocess.py", line 581, in check_call
2018-03-30 01:58:27 DEBUG config-changed raise CalledProcessError(retcode, cmd)
2018-03-30 01:58:27 DEBUG config-changed subprocess.CalledProcessError: Command '['leader-set', 'fsid=9a557a74-33bd-11e8-aedb-00163ef9463f', 'monitor-secret=AQBemb1ajb3qLRAAlPxv893HqNK1oos2V1jUzg==']' returned non-zero exit status 1
2018-03-30 01:58:27 ERROR juju.worker.uniter.operation runhook.go:114 hook "config-changed" failed: exit status 1

I am not sure how the charm could or should handle this differently?

Adding juju task.