← Back to team overview

yahoo-eng-team team mailing list archive

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

[Bug 1440192] [NEW] DB Deadlock: Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO ipallocations

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

If DVR is enabled, and the following 2 Tempest tests are run
concurrently:

tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcp_stateful_router[id-e98f65db-68f4-4330-9fea-abd8c5192d4d]
tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcpv6_64_subnets[id-4256c61d-c538-41ea-9147-3c450c36669e]

then the test_dhcpv6_64_subnets test case will fail intermittently
(about 1 in 6 tries) with the following error in the Neutron server log:

2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource DBDeadlock:
(OperationalError) (1205, 'Lock wait timeout exceeded; try restarting
transaction') 'INSERT INTO ipallocations (port_id, ip_address,
subnet_id, network_id) VALUES (%s, %s, %s, %s)' ('96c6cc59-5ebd-
4f91-bf28-ca60b31f71e1', '2003::f816:3eff:fe1e:ba9e',
'4a339f40-6038-47c7-90e4-338fb4d14d6b', 'b718484d-5e8a-4ad7-bcfa-
668d519942b7')

And the following traceback is observed:
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource Traceback (most recent call last):
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result = method(request=request, **args)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 461, in create
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     obj = obj_creator(request.context, **kwargs)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/plugins/ml2/plugin.py", line 791, in create_subnet
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result, mech_context = self._create_subnet_db(context, subnet)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/plugins/ml2/plugin.py", line 782, in _create_subnet_db
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result = super(Ml2Plugin, self).create_subnet(context, subnet)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1348, in create_subnet
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return self._create_subnet_from_implicit_pool(context, subnet)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1284, in _create_subnet_from_implicit_pool
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._add_auto_addrs_on_network_ports(context, subnet)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.rollback()
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.commit()
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 377, in commit
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._prepare_impl()
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 357, in _prepare_impl
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.session.flush()
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1919, in flush
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._flush(objects)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2037, in _flush
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     transaction.rollback(_capture_exception=True)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2001, in _flush
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     flush_context.execute()
m2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     rec.execute(self)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     uow
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     mapper, table, insert)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 570, in _emit_insert_statements
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     execute(statement, multiparams)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     context)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/compat/handle_error.py", line 261, in _handle_dbapi_exception
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     e, statement, parameters, cursor, context)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     context)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.errorhandler(self, exc, value)
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     raise errorclass, errorvalue

Steps to Reproduce:
================
(1) Run DevStack with Q_DVR_MODE=dvr_snat in localrc/local.conf
(2) cd /opt/stack/tempest
(3) Create a file called "my_load_list_file" with the following content:

tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcpv6_64_subnets[id-4256c61d-c538-41ea-9147-3c450c36669e]
tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcp_stateful_router[id-e98f65db-68f4-4330-9fea-abd8c5192d4d]

(4) Run 'testr init'
(5) Run the following test loop:

for i in `seq 1 50`; do testr run --load-list=my_load_list_file >> my_tempest_log; done
 
You should see the failure in approximately 1 in 6 runs.

** Affects: neutron
     Importance: Undecided
     Assignee: Dane LeBlanc (leblancd)
         Status: New

** Changed in: neutron
     Assignee: (unassigned) => Dane LeBlanc (leblancd)

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1440192

Title:
  DB Deadlock: Lock wait timeout exceeded; try restarting transaction')
  'INSERT INTO ipallocations

Status in OpenStack Neutron (virtual network service):
  New

Bug description:
  If DVR is enabled, and the following 2 Tempest tests are run
  concurrently:

  tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcp_stateful_router[id-e98f65db-68f4-4330-9fea-abd8c5192d4d]
  tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcpv6_64_subnets[id-4256c61d-c538-41ea-9147-3c450c36669e]

  then the test_dhcpv6_64_subnets test case will fail intermittently
  (about 1 in 6 tries) with the following error in the Neutron server
  log:

  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource DBDeadlock:
  (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting
  transaction') 'INSERT INTO ipallocations (port_id, ip_address,
  subnet_id, network_id) VALUES (%s, %s, %s, %s)' ('96c6cc59-5ebd-
  4f91-bf28-ca60b31f71e1', '2003::f816:3eff:fe1e:ba9e',
  '4a339f40-6038-47c7-90e4-338fb4d14d6b', 'b718484d-5e8a-4ad7-bcfa-
  668d519942b7')

  And the following traceback is observed:
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource Traceback (most recent call last):
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result = method(request=request, **args)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 461, in create
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     obj = obj_creator(request.context, **kwargs)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/plugins/ml2/plugin.py", line 791, in create_subnet
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result, mech_context = self._create_subnet_db(context, subnet)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/plugins/ml2/plugin.py", line 782, in _create_subnet_db
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     result = super(Ml2Plugin, self).create_subnet(context, subnet)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1348, in create_subnet
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return self._create_subnet_from_implicit_pool(context, subnet)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1284, in _create_subnet_from_implicit_pool
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._add_auto_addrs_on_network_ports(context, subnet)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.rollback()
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.commit()
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 377, in commit
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._prepare_impl()
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 357, in _prepare_impl
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.session.flush()
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1919, in flush
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self._flush(objects)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2037, in _flush
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     transaction.rollback(_capture_exception=True)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2001, in _flush
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     flush_context.execute()
  m2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     rec.execute(self)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     uow
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     mapper, table, insert)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 570, in _emit_insert_statements
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     execute(statement, multiparams)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     context)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/compat/handle_error.py", line 261, in _handle_dbapi_exception
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     e, statement, parameters, cursor, context)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     context)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     self.errorhandler(self, exc, value)
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
  2015-04-03 15:29:14.696 TRACE neutron.api.v2.resource     raise errorclass, errorvalue

  Steps to Reproduce:
  ================
  (1) Run DevStack with Q_DVR_MODE=dvr_snat in localrc/local.conf
  (2) cd /opt/stack/tempest
  (3) Create a file called "my_load_list_file" with the following content:

  tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcpv6_64_subnets[id-4256c61d-c538-41ea-9147-3c450c36669e]
  tempest.api.network.test_dhcp_ipv6.NetworksTestDHCPv6.test_dhcp_stateful_router[id-e98f65db-68f4-4330-9fea-abd8c5192d4d]

  (4) Run 'testr init'
  (5) Run the following test loop:

  for i in `seq 1 50`; do testr run --load-list=my_load_list_file >> my_tempest_log; done
   
  You should see the failure in approximately 1 in 6 runs.

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

Follow ups

References

  Thread Previous • Date Previous • • Thread Next