← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #73947

[Bug 1783402] [NEW] DBDeadlock during test_resize_server_revert_with_volume_attached when setting migration.status='migrating'

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

http://logs.openstack.org/71/538371/9/gate/tempest-full/1e316ab/job-
output.txt.gz#_2018-07-24_18_29_35_901732

2018-07-24 18:29:35.901732 | controller | {0} tempest.api.compute.servers.test_server_actions.ServerActionsTestJSON.test_resize_server_revert_with_volume_attached [38.878445s] ... FAILED
2018-07-24 18:29:35.901847 | controller |
2018-07-24 18:29:35.902454 | controller | Captured traceback-1:
2018-07-24 18:29:35.902557 | controller | ~~~~~~~~~~~~~~~~~~~~~
2018-07-24 18:29:35.902687 | controller |     Traceback (most recent call last):
2018-07-24 18:29:35.903533 | controller |       File "tempest/api/compute/servers/test_server_actions.py", line 62, in tearDown
2018-07-24 18:29:35.903674 | controller |         self.server_check_teardown()
2018-07-24 18:29:35.904127 | controller |       File "tempest/api/compute/base.py", line 206, in server_check_teardown
2018-07-24 18:29:35.904224 | controller |         cls.server_id)
2018-07-24 18:29:35.904446 | controller |       File "tempest/common/waiters.py", line 124, in wait_for_server_termination
2018-07-24 18:29:35.904636 | controller |         raise lib_exc.DeleteErrorException(resource_id=server_id)
2018-07-24 18:29:35.904947 | controller |     tempest.lib.exceptions.DeleteErrorException: Resource 0c6727db-4471-480a-a328-a6aa1fdd6f4a failed to delete and is in ERROR status
2018-07-24 18:29:35.904993 | controller |
2018-07-24 18:29:35.905025 | controller |
2018-07-24 18:29:35.905092 | controller | Captured traceback-2:
2018-07-24 18:29:35.905160 | controller | ~~~~~~~~~~~~~~~~~~~~~
2018-07-24 18:29:35.905257 | controller |     Traceback (most recent call last):
2018-07-24 18:29:35.905409 | controller |       File "tempest/api/compute/base.py", line 527, in _detach_volume
2018-07-24 18:29:35.905561 | controller |         self.servers_client.detach_volume(server['id'], volume['id'])
2018-07-24 18:29:35.905745 | controller |       File "tempest/lib/services/compute/servers_client.py", line 447, in detach_volume
2018-07-24 18:29:35.905831 | controller |         (server_id, volume_id))
2018-07-24 18:29:35.905979 | controller |       File "tempest/lib/common/rest_client.py", line 310, in delete
2018-07-24 18:29:35.906871 | controller |         return self.request('DELETE', url, extra_headers, headers, body)
2018-07-24 18:29:35.907065 | controller |       File "tempest/lib/services/compute/base_compute_client.py", line 48, in request
2018-07-24 18:29:35.907204 | controller |         method, url, extra_headers, headers, body, chunked)
2018-07-24 18:29:35.907509 | controller |       File "tempest/lib/common/rest_client.py", line 670, in request
2018-07-24 18:29:35.907623 | controller |         self._error_checker(resp, resp_body)
2018-07-24 18:29:35.907787 | controller |       File "tempest/lib/common/rest_client.py", line 791, in _error_checker
2018-07-24 18:29:35.907916 | controller |         raise exceptions.Conflict(resp_body, resp=resp)
2018-07-24 18:29:35.908078 | controller |     tempest.lib.exceptions.Conflict: Conflict with state of target resource
2018-07-24 18:29:35.908363 | controller |     Details: {u'message': u"Cannot 'detach_volume' instance 0c6727db-4471-480a-a328-a6aa1fdd6f4a while it is in vm_state error", u'code': 409}
2018-07-24 18:29:35.908403 | controller |
2018-07-24 18:29:35.908433 | controller |
2018-07-24 18:29:35.908497 | controller | Captured traceback:
2018-07-24 18:29:35.908561 | controller | ~~~~~~~~~~~~~~~~~~~
2018-07-24 18:29:35.908659 | controller |     Traceback (most recent call last):
2018-07-24 18:29:35.908793 | controller |       File "tempest/lib/decorators.py", line 67, in wrapper
2018-07-24 18:29:35.908854 | controller |         raise exc
2018-07-24 18:29:35.909108 | controller |     tempest.exceptions.BuildErrorException: Server 0c6727db-4471-480a-a328-a6aa1fdd6f4a failed to build and is in ERROR status
2018-07-24 18:29:35.909760 | controller |     Details: {u'message': u"Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [par", u'code': 500, u'created': u'2018-07-24T18:29:25Z'}

>From the n-cpu logs:

http://logs.openstack.org/71/538371/9/gate/tempest-
full/1e316ab/controller/logs/screen-n-cpu.txt.gz#_Jul_24_18_29_24_941180

Jul 24 18:29:24.941180 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [None req-1c821bf3-68d3-4b62-9d05-70c36756f934 tempest-ServerActionsTestJSON-665458078 tempest-ServerActionsTestJSON-665458078] [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] Setting instance vm_state to ERROR: RemoteError: Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)
Jul 24 18:29:24.941989 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: [u'Traceback (most recent call last):\n', u'  File "/opt/stack/nova/nova/conductor/manager.py", line 126, in _object_dispatch\n    return getattr(target, method)(*args, **kwargs)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper\n    return fn(self, *args, **kwargs)\n', u'  File "/opt/stack/nova/nova/objects/migration.py", line 164, in save\n    db_migration = db.migration_update(self._context, self.id, updates)\n', u'  File "/opt/stack/nova/nova/db/api.py", line 518, in migration_update\n    return IMPL.migration_update(context, id, values)\n', u'  File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 225, in wrapped\n    return f(context, *args, **kwargs)\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope\n    yield resource\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session\n    self.session.rollback()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__\n    self.force_reraise()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise\n    six.reraise(self.type_, self.value, self.tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session\n    self._end_session_transaction(self.session)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction\n    session.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 943, in commit\n    self.transaction.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in commit\n    self._prepare_impl()\n', u'
Jul 24 18:29:24.942653 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in _prepare_impl\n    self.session.flush()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2254, in flush\n    self._flush(objects)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2380, in _flush\n    transaction.rollback(_capture_exception=True)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__\n    compat.reraise(exc_type, exc_value, exc_tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2344, in _flush\n    flush_context.execute()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute\n    rec.execute(self)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute\n    uow\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj\n    mapper, table, update)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements\n    execute(statement, multiparams)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 948, in execute\n    return meth(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement\n    compiled_sql, distilled_params\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception\n    util.raise_from_cause(newraise, exc_info)\n', u'  File "/usr/local/lib/python2
Jul 24 18:29:24.943201 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: .7/dist-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb, cause=cause)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 509, in do_execute\n    cursor.execute(statement, parameters)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 170, in execute\n    result = self._query(query)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 328, in _query\n    conn.query(q)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 516, in query\n    self._affected_rows = self._read_query_result(unbuffered=unbuffered)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 727, in _read_query_result\n    result.read()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1066, in read\n    first_packet = self.connection._read_packet()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 683, in _read_packet\n    packet.check_error()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/protocol.py", line 220, in check_error\n    err.raise_mysql_exception(self._data)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 109, in raise_mysql_exception\n    raise errorclass(errno, errval)\n', u"DBDeadlock: (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)\n"].
Jul 24 18:29:24.943760 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] Traceback (most recent call last):
Jul 24 18:29:24.943998 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/compute/manager.py", line 7755, in _error_out_instance_on_exception
Jul 24 18:29:24.944257 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     yield
Jul 24 18:29:24.944483 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/compute/manager.py", line 4306, in _resize_instance
Jul 24 18:29:24.944716 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     migration.save()
Jul 24 18:29:24.944941 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 210, in wrapper
Jul 24 18:29:24.945165 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     ctxt, self, fn.__name__, args, kwargs)
Jul 24 18:29:24.945389 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 246, in object_action
Jul 24 18:29:24.945613 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     objmethod=objmethod, args=args, kwargs=kwargs)
Jul 24 18:29:24.945852 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 179, in call
Jul 24 18:29:24.946075 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     retry=self.retry)
Jul 24 18:29:24.946323 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 133, in _send
Jul 24 18:29:24.946547 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     retry=retry)
Jul 24 18:29:24.946784 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 584, in send
Jul 24 18:29:24.947021 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     call_monitor_timeout, retry=retry)
Jul 24 18:29:24.947244 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 575, in _send
Jul 24 18:29:24.947484 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     raise result
Jul 24 18:29:24.947710 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] RemoteError: Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)
Jul 24 18:29:24.948355 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] [u'Traceback (most recent call last):\n', u'  File "/opt/stack/nova/nova/conductor/manager.py", line 126, in _object_dispatch\n    return getattr(target, method)(*args, **kwargs)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper\n    return fn(self, *args, **kwargs)\n', u'  File "/opt/stack/nova/nova/objects/migration.py", line 164, in save\n    db_migration = db.migration_update(self._context, self.id, updates)\n', u'  File "/opt/stack/nova/nova/db/api.py", line 518, in migration_update\n    return IMPL.migration_update(context, id, values)\n', u'  File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 225, in wrapped\n    return f(context, *args, **kwargs)\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope\n    yield resource\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session\n    self.session.rollback()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__\n    self.force_reraise()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise\n    six.reraise(self.type_, self.value, self.tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session\n    self._end_session_transaction(self.session)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction\n    session.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 943, in commit\n    self.transaction.commit()\n', u'  File "/usr/local/lib/python2.7/dist-pa
Jul 24 18:29:24.948921 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ckages/sqlalchemy/orm/session.py", line 467, in commit\n    self._prepare_impl()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in _prepare_impl\n    self.session.flush()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2254, in flush\n    self._flush(objects)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2380, in _flush\n    transaction.rollback(_capture_exception=True)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__\n    compat.reraise(exc_type, exc_value, exc_tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2344, in _flush\n    flush_context.execute()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute\n    rec.execute(self)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute\n    uow\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj\n    mapper, table, update)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements\n    execute(statement, multiparams)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 948, in execute\n    return meth(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement\n    compiled_sql, distilled_params\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exce
Jul 24 18:29:24.949470 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ption\n    util.raise_from_cause(newraise, exc_info)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb, cause=cause)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 509, in do_execute\n    cursor.execute(statement, parameters)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 170, in execute\n    result = self._query(query)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 328, in _query\n    conn.query(q)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 516, in query\n    self._affected_rows = self._read_query_result(unbuffered=unbuffered)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 727, in _read_query_result\n    result.read()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1066, in read\n    first_packet = self.connection._read_packet()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 683, in _read_packet\n    packet.check_error()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/protocol.py", line 220, in check_error\n    err.raise_mysql_exception(self._data)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 109, in raise_mysql_exception\n    raise errorclass(errno, errval)\n', u"DBDeadlock: (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)\n"].
Jul 24 18:29:24.950508 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] 

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Setting%20instance%20vm_state%20to%20ERROR%5C%22%20AND%20message%3A%5C%22DBDeadlock%5C%22%20AND%20message%3A%5C%22u'UPDATE%20migrations%20SET%5C%22%20AND%20message%3A%5C%22'status'%3A%20u'migrating'%5C%22%20AND%20tags%3A%5C%22screen-n-cpu.txt%5C%22&from=7d

** Affects: nova
     Importance: Medium
         Status: Confirmed


** Tags: db gate-failure resize

** Tags added: db gate-failure resize

** Changed in: nova
       Status: New => Confirmed

** Changed in: nova
   Importance: Undecided => Medium

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1783402

Title:
  DBDeadlock during test_resize_server_revert_with_volume_attached when
  setting migration.status='migrating'

Status in OpenStack Compute (nova):
  Confirmed

Bug description:
  http://logs.openstack.org/71/538371/9/gate/tempest-full/1e316ab/job-
  output.txt.gz#_2018-07-24_18_29_35_901732

  2018-07-24 18:29:35.901732 | controller | {0} tempest.api.compute.servers.test_server_actions.ServerActionsTestJSON.test_resize_server_revert_with_volume_attached [38.878445s] ... FAILED
  2018-07-24 18:29:35.901847 | controller |
  2018-07-24 18:29:35.902454 | controller | Captured traceback-1:
  2018-07-24 18:29:35.902557 | controller | ~~~~~~~~~~~~~~~~~~~~~
  2018-07-24 18:29:35.902687 | controller |     Traceback (most recent call last):
  2018-07-24 18:29:35.903533 | controller |       File "tempest/api/compute/servers/test_server_actions.py", line 62, in tearDown
  2018-07-24 18:29:35.903674 | controller |         self.server_check_teardown()
  2018-07-24 18:29:35.904127 | controller |       File "tempest/api/compute/base.py", line 206, in server_check_teardown
  2018-07-24 18:29:35.904224 | controller |         cls.server_id)
  2018-07-24 18:29:35.904446 | controller |       File "tempest/common/waiters.py", line 124, in wait_for_server_termination
  2018-07-24 18:29:35.904636 | controller |         raise lib_exc.DeleteErrorException(resource_id=server_id)
  2018-07-24 18:29:35.904947 | controller |     tempest.lib.exceptions.DeleteErrorException: Resource 0c6727db-4471-480a-a328-a6aa1fdd6f4a failed to delete and is in ERROR status
  2018-07-24 18:29:35.904993 | controller |
  2018-07-24 18:29:35.905025 | controller |
  2018-07-24 18:29:35.905092 | controller | Captured traceback-2:
  2018-07-24 18:29:35.905160 | controller | ~~~~~~~~~~~~~~~~~~~~~
  2018-07-24 18:29:35.905257 | controller |     Traceback (most recent call last):
  2018-07-24 18:29:35.905409 | controller |       File "tempest/api/compute/base.py", line 527, in _detach_volume
  2018-07-24 18:29:35.905561 | controller |         self.servers_client.detach_volume(server['id'], volume['id'])
  2018-07-24 18:29:35.905745 | controller |       File "tempest/lib/services/compute/servers_client.py", line 447, in detach_volume
  2018-07-24 18:29:35.905831 | controller |         (server_id, volume_id))
  2018-07-24 18:29:35.905979 | controller |       File "tempest/lib/common/rest_client.py", line 310, in delete
  2018-07-24 18:29:35.906871 | controller |         return self.request('DELETE', url, extra_headers, headers, body)
  2018-07-24 18:29:35.907065 | controller |       File "tempest/lib/services/compute/base_compute_client.py", line 48, in request
  2018-07-24 18:29:35.907204 | controller |         method, url, extra_headers, headers, body, chunked)
  2018-07-24 18:29:35.907509 | controller |       File "tempest/lib/common/rest_client.py", line 670, in request
  2018-07-24 18:29:35.907623 | controller |         self._error_checker(resp, resp_body)
  2018-07-24 18:29:35.907787 | controller |       File "tempest/lib/common/rest_client.py", line 791, in _error_checker
  2018-07-24 18:29:35.907916 | controller |         raise exceptions.Conflict(resp_body, resp=resp)
  2018-07-24 18:29:35.908078 | controller |     tempest.lib.exceptions.Conflict: Conflict with state of target resource
  2018-07-24 18:29:35.908363 | controller |     Details: {u'message': u"Cannot 'detach_volume' instance 0c6727db-4471-480a-a328-a6aa1fdd6f4a while it is in vm_state error", u'code': 409}
  2018-07-24 18:29:35.908403 | controller |
  2018-07-24 18:29:35.908433 | controller |
  2018-07-24 18:29:35.908497 | controller | Captured traceback:
  2018-07-24 18:29:35.908561 | controller | ~~~~~~~~~~~~~~~~~~~
  2018-07-24 18:29:35.908659 | controller |     Traceback (most recent call last):
  2018-07-24 18:29:35.908793 | controller |       File "tempest/lib/decorators.py", line 67, in wrapper
  2018-07-24 18:29:35.908854 | controller |         raise exc
  2018-07-24 18:29:35.909108 | controller |     tempest.exceptions.BuildErrorException: Server 0c6727db-4471-480a-a328-a6aa1fdd6f4a failed to build and is in ERROR status
  2018-07-24 18:29:35.909760 | controller |     Details: {u'message': u"Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [par", u'code': 500, u'created': u'2018-07-24T18:29:25Z'}

  From the n-cpu logs:

  http://logs.openstack.org/71/538371/9/gate/tempest-
  full/1e316ab/controller/logs/screen-n-cpu.txt.gz#_Jul_24_18_29_24_941180

  Jul 24 18:29:24.941180 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [None req-1c821bf3-68d3-4b62-9d05-70c36756f934 tempest-ServerActionsTestJSON-665458078 tempest-ServerActionsTestJSON-665458078] [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] Setting instance vm_state to ERROR: RemoteError: Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)
  Jul 24 18:29:24.941989 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: [u'Traceback (most recent call last):\n', u'  File "/opt/stack/nova/nova/conductor/manager.py", line 126, in _object_dispatch\n    return getattr(target, method)(*args, **kwargs)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper\n    return fn(self, *args, **kwargs)\n', u'  File "/opt/stack/nova/nova/objects/migration.py", line 164, in save\n    db_migration = db.migration_update(self._context, self.id, updates)\n', u'  File "/opt/stack/nova/nova/db/api.py", line 518, in migration_update\n    return IMPL.migration_update(context, id, values)\n', u'  File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 225, in wrapped\n    return f(context, *args, **kwargs)\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope\n    yield resource\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session\n    self.session.rollback()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__\n    self.force_reraise()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise\n    six.reraise(self.type_, self.value, self.tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session\n    self._end_session_transaction(self.session)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction\n    session.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 943, in commit\n    self.transaction.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in commit\n    self._prepare_impl()\n', u'
  Jul 24 18:29:24.942653 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in _prepare_impl\n    self.session.flush()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2254, in flush\n    self._flush(objects)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2380, in _flush\n    transaction.rollback(_capture_exception=True)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__\n    compat.reraise(exc_type, exc_value, exc_tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2344, in _flush\n    flush_context.execute()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute\n    rec.execute(self)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute\n    uow\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj\n    mapper, table, update)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements\n    execute(statement, multiparams)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 948, in execute\n    return meth(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement\n    compiled_sql, distilled_params\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception\n    util.raise_from_cause(newraise, exc_info)\n', u'  File "/usr/local/lib/python2
  Jul 24 18:29:24.943201 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: .7/dist-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb, cause=cause)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 509, in do_execute\n    cursor.execute(statement, parameters)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 170, in execute\n    result = self._query(query)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 328, in _query\n    conn.query(q)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 516, in query\n    self._affected_rows = self._read_query_result(unbuffered=unbuffered)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 727, in _read_query_result\n    result.read()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1066, in read\n    first_packet = self.connection._read_packet()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 683, in _read_packet\n    packet.check_error()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/protocol.py", line 220, in check_error\n    err.raise_mysql_exception(self._data)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 109, in raise_mysql_exception\n    raise errorclass(errno, errval)\n', u"DBDeadlock: (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)\n"].
  Jul 24 18:29:24.943760 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] Traceback (most recent call last):
  Jul 24 18:29:24.943998 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/compute/manager.py", line 7755, in _error_out_instance_on_exception
  Jul 24 18:29:24.944257 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     yield
  Jul 24 18:29:24.944483 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/compute/manager.py", line 4306, in _resize_instance
  Jul 24 18:29:24.944716 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     migration.save()
  Jul 24 18:29:24.944941 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 210, in wrapper
  Jul 24 18:29:24.945165 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     ctxt, self, fn.__name__, args, kwargs)
  Jul 24 18:29:24.945389 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 246, in object_action
  Jul 24 18:29:24.945613 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     objmethod=objmethod, args=args, kwargs=kwargs)
  Jul 24 18:29:24.945852 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 179, in call
  Jul 24 18:29:24.946075 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     retry=self.retry)
  Jul 24 18:29:24.946323 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 133, in _send
  Jul 24 18:29:24.946547 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     retry=retry)
  Jul 24 18:29:24.946784 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 584, in send
  Jul 24 18:29:24.947021 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     call_monitor_timeout, retry=retry)
  Jul 24 18:29:24.947244 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 575, in _send
  Jul 24 18:29:24.947484 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a]     raise result
  Jul 24 18:29:24.947710 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] RemoteError: Remote error: DBDeadlock (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)
  Jul 24 18:29:24.948355 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] [u'Traceback (most recent call last):\n', u'  File "/opt/stack/nova/nova/conductor/manager.py", line 126, in _object_dispatch\n    return getattr(target, method)(*args, **kwargs)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper\n    return fn(self, *args, **kwargs)\n', u'  File "/opt/stack/nova/nova/objects/migration.py", line 164, in save\n    db_migration = db.migration_update(self._context, self.id, updates)\n', u'  File "/opt/stack/nova/nova/db/api.py", line 518, in migration_update\n    return IMPL.migration_update(context, id, values)\n', u'  File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 225, in wrapped\n    return f(context, *args, **kwargs)\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope\n    yield resource\n', u'  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session\n    self.session.rollback()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__\n    self.force_reraise()\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise\n    six.reraise(self.type_, self.value, self.tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session\n    self._end_session_transaction(self.session)\n', u'  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction\n    session.commit()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 943, in commit\n    self.transaction.commit()\n', u'  File "/usr/local/lib/python2.7/dist-pa
  Jul 24 18:29:24.948921 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ckages/sqlalchemy/orm/session.py", line 467, in commit\n    self._prepare_impl()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in _prepare_impl\n    self.session.flush()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2254, in flush\n    self._flush(objects)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2380, in _flush\n    transaction.rollback(_capture_exception=True)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__\n    compat.reraise(exc_type, exc_value, exc_tb)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2344, in _flush\n    flush_context.execute()\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute\n    rec.execute(self)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute\n    uow\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj\n    mapper, table, update)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements\n    execute(statement, multiparams)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 948, in execute\n    return meth(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement\n    compiled_sql, distilled_params\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exce
  Jul 24 18:29:24.949470 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ption\n    util.raise_from_cause(newraise, exc_info)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb, cause=cause)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context\n    context)\n', u'  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 509, in do_execute\n    cursor.execute(statement, parameters)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 170, in execute\n    result = self._query(query)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 328, in _query\n    conn.query(q)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 516, in query\n    self._affected_rows = self._read_query_result(unbuffered=unbuffered)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 727, in _read_query_result\n    result.read()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1066, in read\n    first_packet = self.connection._read_packet()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 683, in _read_packet\n    packet.check_error()\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/protocol.py", line 220, in check_error\n    err.raise_mysql_exception(self._data)\n', u'  File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 109, in raise_mysql_exception\n    raise errorclass(errno, errval)\n', u"DBDeadlock: (pymysql.err.OperationalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'UPDATE migrations SET updated_at=%(updated_at)s, status=%(status)s WHERE migrations.id = %(migrations_id)s'] [parameters: {'status': u'migrating', 'migrations_id': 9, 'updated_at': datetime.datetime(2018, 7, 24, 18, 29, 24, 788513)}] (Background on this error at: http://sqlalche.me/e/e3q8)\n"].
  Jul 24 18:29:24.950508 ubuntu-xenial-rax-dfw-0000933691 nova-compute[17316]: ERROR nova.compute.manager [instance: 0c6727db-4471-480a-a328-a6aa1fdd6f4a] 

  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Setting%20instance%20vm_state%20to%20ERROR%5C%22%20AND%20message%3A%5C%22DBDeadlock%5C%22%20AND%20message%3A%5C%22u'UPDATE%20migrations%20SET%5C%22%20AND%20message%3A%5C%22'status'%3A%20u'migrating'%5C%22%20AND%20tags%3A%5C%22screen-n-cpu.txt%5C%22&from=7d

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1783402/+subscriptions
  Thread Previous • Date Previous • • Thread Next