Ignoring CalledProcessError during nova-api database migration: Lost connection to MySQL server during query

Bug #1953501 reported by Felipe Reyes
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Nova Cloud Controller Charm
New
Undecided
Unassigned

Bug Description

During a fresh deployment nova-manage db_api sync failed due to mysql got disconnected from the nova-cloud-controller unit in the middle of the syncing, this error got logged, but the hook ignored the failure

2021-12-06 19:44:59 INFO unit.nova-cloud-controller/0.juju-log server.go:327 shared-db:13: Ignoring CalledProcessError during nova-api database migration

When 'nova-manage api_db sync' fails there is an assumption that the cell initialization was successful and there is no retry[0], other calls to nova-manage are wrapped with the retry_on_exception() decorator[1]

Attempts to run "nova-manage api_db sync" didn't succeed. those resulted in the following error: https://pastebin.ubuntu.com/p/YFryTFwFdd/

juju export-bundle -> https://paste.ubuntu.com/p/YWDs4r65Cp/
Env: Focal Xena

[0] https://opendev.org/openstack/charm-nova-cloud-controller/src/branch/master/hooks/nova_cc_utils.py#L774

[1] https://opendev.org/openstack/charm-nova-cloud-controller/src/branch/master/hooks/nova_cc_utils.py#L751

Pretty printted error:

An error has occurred:
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 609, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute
    result = self._query(query)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 310, in _query
    conn.query(q)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result
    result.read()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1156, in read
    first_packet = self.connection._read_packet()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 692, in _read_packet
    packet_header = self._read_bytes(4)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 748, in _read_bytes
    raise err.OperationalError(
pymysql.err.OperationalError: (2013, 'Lost connection to MySQL server during query')

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/nova/cmd/manage.py", line 3178, in main
    ret = fn(*fn_args, **fn_kwargs)
  File "/usr/lib/python3/dist-packages/nova/cmd/manage.py", line 611, in sync
    return migration.db_sync(version, database='api')
  File "/usr/lib/python3/dist-packages/nova/db/migration.py", line 154, in db_sync
    _upgrade_alembic(engine, config, version)
  File "/usr/lib/python3/dist-packages/nova/db/migration.py", line 109, in _upgrade_alembic
    alembic_api.upgrade(config, version or 'head')
  File "/usr/lib/python3/dist-packages/alembic/command.py", line 294, in upgrade
    script.run_env()
  File "/usr/lib/python3/dist-packages/alembic/script/base.py", line 490, in run_env
    util.load_python_file(self.dir, "env.py")
  File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 97, in load_python_file
    module = load_module_py(module_id, path)
  File "/usr/lib/python3/dist-packages/alembic/util/compat.py", line 184, in load_module_py
    spec.loader.exec_module(module)
  File "<frozen importlib._bootstrap_external>", line 848, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/lib/python3/dist-packages/nova/db/api/migrations/env.py", line 94, in <module>
    run_migrations_online()
  File "/usr/lib/python3/dist-packages/nova/db/api/migrations/env.py", line 88, in run_migrations_online
    context.run_migrations()
  File "<string>", line 8, in run_migrations
  File "/usr/lib/python3/dist-packages/alembic/runtime/environment.py", line 813, in run_migrations
    self.get_context().run_migrations(**kw)
  File "/usr/lib/python3/dist-packages/alembic/runtime/migration.py", line 561, in run_migrations
    step.migration_fn(**kw)
  File "/usr/lib/python3/dist-packages/nova/db/api/migrations/versions/d67eeaabee36_initial_version.py", line 356, in upgrade
    op.create_table(
  File "<string>", line 8, in create_table
  File "<string>", line 3, in create_table
  File "/usr/lib/python3/dist-packages/alembic/operations/ops.py", line 1087, in create_table
    return operations.invoke(op)
  File "/usr/lib/python3/dist-packages/alembic/operations/base.py", line 354, in invoke
    return fn(self, operation)
  File "/usr/lib/python3/dist-packages/alembic/operations/toimpl.py", line 101, in create_table
    operations.impl.create_table(table)
  File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 277, in create_table
    self._exec(schema.CreateTable(table))
  File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 146, in _exec
    return conn.execute(construct, multiparams)
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1011, in execute
    return meth(self, multiparams, params)
  File "/usr/lib/python3/dist-packages/sqlalchemy/sql/ddl.py", line 72, in _execute_on_connection
    return connection._execute_ddl(self, multiparams, params)
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1068, in _execute_ddl
    ret = self._execute_context(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1316, in _execute_context
    self._handle_dbapi_exception(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1508, in _handle_dbapi_exception
    util.raise_(newraise, with_traceback=exc_info[2], from_=e)
  File "/usr/lib/python3/dist-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 609, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute
    result = self._query(query)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 310, in _query
    conn.query(q)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result
    result.read()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1156, in read
    first_packet = self.connection._read_packet()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 692, in _read_packet
    packet_header = self._read_bytes(4)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 748, in _read_bytes
    raise err.OperationalError(
oslo_db.exception.DBConnectionError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
[SQL:
CREATE TABLE consumers (
 created_at DATETIME,
 updated_at DATETIME,
 id INTEGER NOT NULL AUTO_INCREMENT,
 uuid VARCHAR(36) NOT NULL,
 project_id INTEGER NOT NULL,
 user_id INTEGER NOT NULL,
 generation INTEGER NOT NULL DEFAULT 0,
 PRIMARY KEY (id),
 CONSTRAINT uniq_consumers0uuid UNIQUE (uuid)
)ENGINE=InnoDB CHARSET=latin1

]
(Background on this error at: http://sqlalche.me/e/13/e3q8)

Raw logged error:
2021-12-06 19:44:59 INFO unit.nova-cloud-controller/0.juju-log server.go:327 shared-db:13: Ignoring CalledProcessError during nova-api database migration
b'An error has occurred:\nTraceback (most recent call last):\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context\n se
lf.dialect.do_execute(\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 609, in do_execute\n cursor.execute(statement, parameters)\n Fil
e "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute\n result = self._query(query)\n File "/usr/lib/python3/dist-packages/pymysql/cursors.py
", line 310, in _query\n conn.query(q)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query\n self._affected_rows = self._read_que
ry_result(unbuffered=unbuffered)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result\n result.read()\n File "/usr/lib/
python3/dist-packages/pymysql/connections.py", line 1156, in read\n first_packet = self.connection._read_packet()\n File "/usr/lib/python3/dist-packages/pymysql/co
nnections.py", line 692, in _read_packet\n packet_header = self._read_bytes(4)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 748, in _read_b
ytes\n raise err.OperationalError(\npymysql.err.OperationalError: (2013, \'Lost connection to MySQL server during query\')\n\nThe above exception was the direct cau
se of the following exception:\n\nTraceback (most recent call last):\n File "/usr/lib/python3/dist-packages/nova/cmd/manage.py", line 3178, in main\n ret = fn(*fn_
args, **fn_kwargs)\n File "/usr/lib/python3/dist-packages/nova/cmd/manage.py", line 611, in sync\n return migration.db_sync(version, database=\'api\')\n File "/us
r/lib/python3/dist-packages/nova/db/migration.py", line 154, in db_sync\n _upgrade_alembic(engine, config, version)\n File "/usr/lib/python3/dist-packages/nova/db/
migration.py", line 109, in _upgrade_alembic\n alembic_api.upgrade(config, version or \'head\')\n File "/usr/lib/python3/dist-packages/alembic/command.py", line 29
4, in upgrade\n script.run_env()\n File "/usr/lib/python3/dist-packages/alembic/script/base.py", line 490, in run_env\n util.load_python_file(self.dir, "env.py"
)\n File "/usr/lib/python3/dist-packages/alembic/util/pyfiles.py", line 97, in load_python_file\n module = load_module_py(module_id, path)\n File "/usr/lib/python
3/dist-packages/alembic/util/compat.py", line 184, in load_module_py\n spec.loader.exec_module(module)\n File "<frozen importlib._bootstrap_external>", line 848, i
n exec_module\n File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed\n File "/usr/lib/python3/dist-packages/nova/db/api/migrations/env.py", l
ine 94, in <module>\n run_migrations_online()\n File "/usr/lib/python3/dist-packages/nova/db/api/migrations/env.py", line 88, in run_migrations_online\n context
.run_migrations()\n File "<string>", line 8, in run_migrations\n File "/usr/lib/python3/dist-packages/alembic/runtime/environment.py", line 813, in run_migrations\n
   self.get_context().run_migrations(**kw)\n File "/usr/lib/python3/dist-packages/alembic/runtime/migration.py", line 561, in run_migrations\n step.migration_fn(**
kw)\n File "/usr/lib/python3/dist-packages/nova/db/api/migrations/versions/d67eeaabee36_initial_version.py", line 356, in upgrade\n op.create_table(\n File "<stri
ng>", line 8, in create_table\n File "<string>", line 3, in create_table\n File "/usr/lib/python3/dist-packages/alembic/operations/ops.py", line 1087, in create_tabl
e\n return operations.invoke(op)\n File "/usr/lib/python3/dist-packages/alembic/operations/base.py", line 354, in invoke\n return fn(self, operation)\n File "/
usr/lib/python3/dist-packages/alembic/operations/toimpl.py", line 101, in create_table\n operations.impl.create_table(table)\n File "/usr/lib/python3/dist-packages
/alembic/ddl/impl.py", line 277, in create_table\n self._exec(schema.CreateTable(table))\n File "/usr/lib/python3/dist-packages/alembic/ddl/impl.py", line 146, in
_exec\n return conn.execute(construct, multiparams)\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1011, in execute\n return meth(self,
 multiparams, params)\n File "/usr/lib/python3/dist-packages/sqlalchemy/sql/ddl.py", line 72, in _execute_on_connection\n return connection._execute_ddl(self, mult
iparams, params)\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1068, in _execute_ddl\n ret = self._execute_context(\n File "/usr/lib/pyt
hon3/dist-packages/sqlalchemy/engine/base.py", line 1316, in _execute_context\n self._handle_dbapi_exception(\n File "/usr/lib/python3/dist-packages/sqlalchemy/eng
ine/base.py", line 1508, in _handle_dbapi_exception\n util.raise_(newraise, with_traceback=exc_info[2], from_=e)\n File "/usr/lib/python3/dist-packages/sqlalchemy/
util/compat.py", line 182, in raise_\n raise exception\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context\n self.
dialect.do_execute(\n File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 609, in do_execute\n cursor.execute(statement, parameters)\n File "
/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute\n result = self._query(query)\n File "/usr/lib/python3/dist-packages/pymysql/cursors.py",
line 310, in _query\n conn.query(q)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query\n self._affected_rows = self._read_query_
result(unbuffered=unbuffered)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result\n result.read()\n File "/usr/lib/pyt
hon3/dist-packages/pymysql/connections.py", line 1156, in read\n first_packet = self.connection._read_packet()\n File "/usr/lib/python3/dist-packages/pymysql/conne
ctions.py", line 692, in _read_packet\n packet_header = self._read_bytes(4)\n File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 748, in _read_byte
s\n raise err.OperationalError(\noslo_db.exception.DBConnectionError: (pymysql.err.OperationalError) (2013, \'Lost connection to MySQL server during query\')\n[SQL:
 \nCREATE TABLE consumers (\n\tcreated_at DATETIME, \n\tupdated_at DATETIME, \n\tid INTEGER NOT NULL AUTO_INCREMENT, \n\tuuid VARCHAR(36) NOT NULL, \n\tproject_id INTE
GER NOT NULL, \n\tuser_id INTEGER NOT NULL, \n\tgeneration INTEGER NOT NULL DEFAULT 0, \n\tPRIMARY KEY (id), \n\tCONSTRAINT uniq_consumers0uuid UNIQUE (uuid)\n)ENGINE=
InnoDB CHARSET=latin1\n\n]\n(Background on this error at: http://sqlalche.me/e/13/e3q8)\n\n'

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.