← Back to team overview

yahoo-eng-team team mailing list archive

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

[Bug 1350463] [NEW] DBDeadlock error in Nova Scheduler

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

Found in example:
http://logs.openstack.org/54/105554/4/check/gate-tempest-dsvm-neutron-large-ops/45501af/logs/screen-n-sch.txt.gz#_2014-07-30_16_26_20_158

2014-07-30 16:26:20.158 17209 ERROR nova.openstack.common.periodic_task [-] Error during SchedulerManager._expire_reservations: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE reservations SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE reservations.deleted = %s AND reservations.expire < %s' (datetime.datetime(2014, 7, 30, 16, 26, 20, 152098), 0, datetime.datetime(2014, 7, 30, 16, 26, 20, 149665))
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/periodic_task.py", line 198, in run_periodic_tasks
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     task(self, context)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/scheduler/manager.py", line 157, in _expire_reservations
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     QUOTAS.expire(context)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/quota.py", line 1401, in expire
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     self._driver.expire(context)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/quota.py", line 651, in expire
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     db.reservation_expire(context)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/api.py", line 1173, in reservation_expire
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     return IMPL.reservation_expire(context)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 149, in wrapper
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     return f(*args, **kwargs)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 3394, in reservation_expire
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     reservation_query.soft_delete(synchronize_session=False)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 694, in soft_delete
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     synchronize_session=synchronize_session)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2690, in update
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     update_op.exec_()
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 816, in exec_
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     self._do_exec()
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 913, in _do_exec
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     update_stmt, params=self.query._params)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 444, in _wrap
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     _raise_if_deadlock_error(e, self.bind.dialect.name)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 427, in _raise_if_deadlock_error
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     raise exception.DBDeadlock(operational_error)
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE reservations SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE reservations.deleted = %s AND reservations.expire < %s' (datetime.datetime(2014, 7, 30, 16, 26, 20, 152098), 0, datetime.datetime(2014, 7, 30, 16, 26, 20, 149665))
2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task 

logstash query shows 35 hits majority in last day:
"Deadlock found when trying to get lock; try restarting transaction" AND filename:"logs/screen-n-sch.txt"

** Affects: nova
     Importance: Undecided
         Status: New

-- 
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/1350463

Title:
  DBDeadlock error in Nova Scheduler

Status in OpenStack Compute (Nova):
  New

Bug description:
  Found in example:
  http://logs.openstack.org/54/105554/4/check/gate-tempest-dsvm-neutron-large-ops/45501af/logs/screen-n-sch.txt.gz#_2014-07-30_16_26_20_158

  2014-07-30 16:26:20.158 17209 ERROR nova.openstack.common.periodic_task [-] Error during SchedulerManager._expire_reservations: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE reservations SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE reservations.deleted = %s AND reservations.expire < %s' (datetime.datetime(2014, 7, 30, 16, 26, 20, 152098), 0, datetime.datetime(2014, 7, 30, 16, 26, 20, 149665))
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/periodic_task.py", line 198, in run_periodic_tasks
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     task(self, context)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/scheduler/manager.py", line 157, in _expire_reservations
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     QUOTAS.expire(context)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/quota.py", line 1401, in expire
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     self._driver.expire(context)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/quota.py", line 651, in expire
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     db.reservation_expire(context)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/api.py", line 1173, in reservation_expire
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     return IMPL.reservation_expire(context)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 149, in wrapper
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     return f(*args, **kwargs)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 3394, in reservation_expire
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     reservation_query.soft_delete(synchronize_session=False)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 694, in soft_delete
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     synchronize_session=synchronize_session)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2690, in update
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     update_op.exec_()
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 816, in exec_
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     self._do_exec()
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 913, in _do_exec
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     update_stmt, params=self.query._params)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 444, in _wrap
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     _raise_if_deadlock_error(e, self.bind.dialect.name)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 427, in _raise_if_deadlock_error
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task     raise exception.DBDeadlock(operational_error)
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE reservations SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE reservations.deleted = %s AND reservations.expire < %s' (datetime.datetime(2014, 7, 30, 16, 26, 20, 152098), 0, datetime.datetime(2014, 7, 30, 16, 26, 20, 149665))
  2014-07-30 16:26:20.158 17209 TRACE nova.openstack.common.periodic_task 

  logstash query shows 35 hits majority in last day:
  "Deadlock found when trying to get lock; try restarting transaction" AND filename:"logs/screen-n-sch.txt"

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1350463/+subscriptions

Follow ups

References

  Thread Previous • Date Previous • • Thread Next