MySQL InnoDB Cluster Charm

[focal] upgrade-charm results in failed hook on /snap/bin/mysqlsh failing

Bug #1890917 reported by Alex Kavanagh
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL InnoDB Cluster Charm
Invalid
Undecided
Unassigned

Bug Description

Trace from failed unit:

unit-mysql-innodb-cluster-2: 07:41:01 INFO unit.mysql-innodb-cluster/2.juju-log Invoking reactive handler: reactive/mysql_innodb_cluster_handlers.py:214:config_changed
unit-mysql-innodb-cluster-2: 07:41:02 DEBUG unit.mysql-innodb-cluster/2.juju-log Writing file /etc/mysql/mysql.conf.d/mysqld.cnf root:mysql 640
unit-mysql-innodb-cluster-2: 07:41:41 ERROR unit.mysql-innodb-cluster/2.juju-log Hook error:
Traceback (most recent call last):
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/__init__.py", line 74, in main
    bus.dispatch(restricted=restricted_mode)
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 390, in dispatch
    _invoke(other_handlers)
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 359, in _invoke
    handler.invoke()
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 181, in invoke
    self._action(*args)
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/charm/reactive/mysql_innodb_cluster_handlers.py", line 220, in config_changed
    instance.wait_until_cluster_available()
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 329, in wrapped_f
    return self.call(f, *args, **kw)
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 409, in call
    do = self.iter(retry_state=retry_state)
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 368, in iter
    raise retry_exc.reraise()
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 186, in reraise
    raise self.last_attempt.result()
  File "/usr/lib/python3.8/concurrent/futures/_base.py", line 432, in result
    return self.__get_result()
  File "/usr/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
    raise self._exception
  File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 412, in call
    result = fn(*args, **kwargs)
  File "lib/charm/openstack/mysql_innodb_cluster.py", line 1403, in wait_until_cluster_available
    self.run_mysqlsh_script(_script)
  File "lib/charm/openstack/mysql_innodb_cluster.py", line 1436, in run_mysqlsh_script
    return subprocess.check_output(cmd, stderr=subprocess.PIPE)
  File "/usr/lib/python3.8/subprocess.py", line 411, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "/usr/lib/python3.8/subprocess.py", line 512, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/snap/bin/mysqlsh', '--no-wizard', '--python', '-f', '/root/snap/mysql-shell/common/tmpu3i6u2qy.py']' returned non-zero exit status 1.

unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm b'snap "mysql-shell" has no updates available\n'
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm Traceback (most recent call last):
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/charm/hooks/upgrade-charm", line 22, in <module>
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm main()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/__init__.py", line 74, in main
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm bus.dispatch(restricted=restricted_mode)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 390, in dispatch
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm _invoke(other_handlers)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 359, in _invoke
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm handler.invoke()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/charms/reactive/bus.py", line 181, in invoke
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm self._action(*args)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/charm/reactive/mysql_innodb_cluster_handlers.py", line 220, in config_changed
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm instance.wait_until_cluster_available()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 329, in wrapped_f
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm return self.call(f, *args, **kw)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 409, in call
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm do = self.iter(retry_state=retry_state)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 368, in iter
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm raise retry_exc.reraise()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 186, in reraise
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm raise self.last_attempt.result()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/usr/lib/python3.8/concurrent/futures/_base.py", line 432, in result
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm return self.__get_result()
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/usr/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm raise self._exception
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/var/lib/juju/agents/unit-mysql-innodb-cluster-2/.venv/lib/python3.8/site-packages/tenacity/__init__.py", line 412, in call
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm result = fn(*args, **kwargs)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "lib/charm/openstack/mysql_innodb_cluster.py", line 1403, in wait_until_cluster_available
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm self.run_mysqlsh_script(_script)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "lib/charm/openstack/mysql_innodb_cluster.py", line 1436, in run_mysqlsh_script
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm return subprocess.check_output(cmd, stderr=subprocess.PIPE)
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/usr/lib/python3.8/subprocess.py", line 411, in check_output
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm File "/usr/lib/python3.8/subprocess.py", line 512, in run
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm raise CalledProcessError(retcode, process.args,
unit-mysql-innodb-cluster-2: 07:41:41 DEBUG unit.mysql-innodb-cluster/2.upgrade-charm subprocess.CalledProcessError: Command '['/snap/bin/mysqlsh', '--no-wizard', '--python', '-f', '/root/snap/mysql-shell/common/tmpu3i6u2qy.py']' returned non-zero exit status 1.
unit-mysql-innodb-cluster-2: 07:41:41 ERROR juju.worker.uniter.operation hook "upgrade-charm" failed: exit status 1

Revision history for this message
Aurelien Lourot (aurelien-lourot) wrote :

@Alex when this happens there is an exception handler [0] that will print the script's stderr. Do you have this part of the log? Did this happen in a CI system and do you have a link to that failed job? Thanks!

0: https://opendev.org/openstack/charm-mysql-innodb-cluster/src/branch/master/src/lib/charm/openstack/mysql_innodb_cluster.py#L657

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

This may be bogus; the test may be wrong; investigating.

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

This seems to be a one off and has not re-occured. Closing for now, but please re-open if new information becomes available.

Changed in charm-mysql-innodb-cluster:
status: New → Invalid
Revision history for this message
Robert Gildein (rgildein) wrote :

I hit same issue during openstack upgrade and I can provide logs from it here [1].

---
[1]: https://pastebin.ubuntu.com/p/5dpjGVrKDz/

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

Other bug subscribers

Remote bug watches

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