hook amqp-relation-changed fails but succeeds on retry

Bug #1862113 reported by David Coronel
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Landscape Charm
New
Undecided
Unassigned

Bug Description

Installing 3 units of Landscape with landscape-server charm rev 35 and rabbitmq-server charm rev 97 sometimes fails on one unit with the following:

28 Jan 2020 14:15:32Z juju-unit error hook failed: "amqp-relation-changed"

The charm retries a few times and eventually succeeds:

$ juju show-status-log landscape-server/2
Time Type Status Message
28 Jan 2020 14:14:15Z juju-unit executing running db-relation-changed hook
28 Jan 2020 14:14:19Z juju-unit idle
28 Jan 2020 14:15:19Z juju-unit executing running amqp-relation-changed hook
28 Jan 2020 14:15:32Z juju-unit error hook failed: "amqp-relation-changed"
28 Jan 2020 14:15:37Z juju-unit executing running amqp-relation-changed hook
28 Jan 2020 14:15:48Z juju-unit error hook failed: "amqp-relation-changed"
28 Jan 2020 14:15:58Z juju-unit executing running amqp-relation-changed hook
28 Jan 2020 14:16:08Z juju-unit error hook failed: "amqp-relation-changed"
28 Jan 2020 14:16:32Z juju-unit executing running amqp-relation-changed hook
28 Jan 2020 14:16:51Z workload maintenance Starting services.
28 Jan 2020 14:17:12Z workload active
28 Jan 2020 14:17:19Z juju-unit executing running db-relation-changed hook
28 Jan 2020 14:17:29Z workload maintenance Restarting services.
28 Jan 2020 14:17:51Z workload active
28 Jan 2020 14:18:11Z juju-unit executing running amqp-relation-changed hook
28 Jan 2020 14:18:23Z workload maintenance Restarting services.
28 Jan 2020 14:18:45Z workload active
28 Jan 2020 14:19:01Z workload maintenance Restarting services.
28 Jan 2020 14:19:24Z workload active
28 Jan 2020 14:19:25Z juju-unit idle

The /var/log/juju/unit-landscape-server-2.log shows this:

[...]
2020-01-28 14:15:45 DEBUG amqp-relation-changed Hit:9 http://archive.ubuntu.com/ubuntu bionic-backports InRelease
2020-01-28 14:15:46 DEBUG amqp-relation-changed Reading package lists...
2020-01-28 14:15:48 DEBUG amqp-relation-changed Loading site configuration...
2020-01-28 14:15:48 DEBUG amqp-relation-changed Traceback (most recent call last):
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/bin/landscape-schema", line 12, in <module>
2020-01-28 14:15:48 DEBUG amqp-relation-changed canonical.landscape.scripts.schema.run()
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/opt/canonical/landscape/canonical/landscape/scripts/schema.py", line 281, in run
2020-01-28 14:15:48 DEBUG amqp-relation-changed _set_two_phase_commit_if_available(zstorm)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/opt/canonical/landscape/canonical/landscape/scripts/schema.py", line 532, in _set_two_phase_commit_if_available
2020-01-28 14:15:48 DEBUG amqp-relation-changed store = zstorm.get(name)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/zope/zstorm.py", line 177, in get
2020-01-28 14:15:48 DEBUG amqp-relation-changed return self.create(name, default_uri)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/zope/zstorm.py", line 153, in create
2020-01-28 14:15:48 DEBUG amqp-relation-changed store = Store(database)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/store.py", line 74, in __init__
2020-01-28 14:15:48 DEBUG amqp-relation-changed self._connection = database.connect(self._event)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/database.py", line 500, in connect
2020-01-28 14:15:48 DEBUG amqp-relation-changed return self.connection_factory(self, event)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/database.py", line 188, in __init__
2020-01-28 14:15:48 DEBUG amqp-relation-changed self._raw_connection = self._database.raw_connect()
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/storm/databases/postgres.py", line 410, in raw_connect
2020-01-28 14:15:48 DEBUG amqp-relation-changed raw_connection = psycopg2.connect(self._dsn)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/dist-packages/psycopg2/__init__.py", line 130, in connect
2020-01-28 14:15:48 DEBUG amqp-relation-changed conn = _connect(dsn, connection_factory=connection_factory, **kwasync)
2020-01-28 14:15:48 DEBUG amqp-relation-changed psycopg2.OperationalError: FATAL: pg_hba.conf rejects connection for host "10.10.50.216", user "jujuadmin_landscape-server", database "p
ostgres", SSL on
2020-01-28 14:15:48 DEBUG amqp-relation-changed FATAL: pg_hba.conf rejects connection for host "10.10.50.216", user "jujuadmin_landscape-server", database "postgres", SSL off
2020-01-28 14:15:48 DEBUG amqp-relation-changed
2020-01-28 14:15:48 DEBUG amqp-relation-changed Traceback (most recent call last):
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/amqp-relation-changed", line 9, in <module>
2020-01-28 14:15:48 DEBUG amqp-relation-changed sys.exit(hook())
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/lib/hook.py", line 24, in __call__
2020-01-28 14:15:48 DEBUG amqp-relation-changed self._run()
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/lib/services.py", line 92, in _run
2020-01-28 14:15:48 DEBUG amqp-relation-changed manager.manage()
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/charmhelpers/core/services/base.py", line 135, in manage
2020-01-28 14:15:48 DEBUG amqp-relation-changed self.reconfigure_services()
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/charmhelpers/core/services/base.py", line 189, in reconfigure_services
2020-01-28 14:15:48 DEBUG amqp-relation-changed self.fire_event('data_ready', service_name)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/charmhelpers/core/services/base.py", line 234, in fire_event
2020-01-28 14:15:48 DEBUG amqp-relation-changed callback(self, service_name, event_name)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/lib/callbacks/scripts.py", line 41, in __call__
2020-01-28 14:15:48 DEBUG amqp-relation-changed self._run(SCHEMA_SCRIPT, options)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/var/lib/juju/agents/unit-landscape-server-2/charm/hooks/lib/callbacks/scripts.py", line 28, in _run
2020-01-28 14:15:48 DEBUG amqp-relation-changed self._subprocess.check_call(command)
2020-01-28 14:15:48 DEBUG amqp-relation-changed File "/usr/lib/python2.7/subprocess.py", line 190, in check_call
2020-01-28 14:15:48 DEBUG amqp-relation-changed raise CalledProcessError(retcode, cmd)
2020-01-28 14:15:48 DEBUG amqp-relation-changed subprocess.CalledProcessError: Command '['/usr/bin/landscape-schema', '--bootstrap']' returned non-zero exit status 1
2020-01-28 14:15:48 ERROR juju.worker.uniter.operation runhook.go:132 hook "amqp-relation-changed" failed: exit status 1
[...]

The rabbitmq-server charm is set to min-cluster-size 3:

  landscape-rabbitmq-server:
    charm: cs:rabbitmq-server
    bindings:
      "": *oam-space
      cluster: *oam-space
      amqp: *oam-space
    options:
      min-cluster-size: 3
    num_units: 3

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.