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