yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1572474] [NEW] [Pluggable IPAM] Deadlock on simultaneous update subnet and ip allocation from subnet

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Pavel Bondar <pbondar@xxxxxxxxxxxx>
Date: Wed, 20 Apr 2016 09:41:22 -0000
Reply-to: Bug 1572474 <1572474@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Observed in logs 'Lock wait timeout exceeded; try restarting transaction' [1], when two requests are concurently executed in neutron:
- request A calls update subnet req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3
- request B calls create port on the same subnet req-ccd11684-ad2b-4937-a3c1-dc46aaa36b2d
As a result both requests  failed.

Request A tries to delete 'ipamallocationpools' for subnet_id and it effectivelly removes 'ipamavailabilityranges' by foreign key.
Request B allocates ip and modifies av_range record in 'ipamavailabilityranges'.
So looks like collision caused by concurent access to 'ipamavailabilityranges' table.

[1] http://logs.openstack.org/23/181023/68/check/gate-tempest-dsvm-
neutron-full/a9180e0/logs/screen-q-svc.txt.gz#_2016-04-19_15_43_05_837

StackTrace with both requests failed:
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'DELETE FROM ipamallocationpools WHERE ipamallocationpools.ipam_subnet_id = %(ipam_subnet_id_1)s'] [parameters: {u'ipam_subnet_id_1': u'0b896671-8cc2-4e08-bbfe-05655e6c479c'}]
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     context)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     _check_mysql_exception(errinfo)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     raise InternalError(errno, errorvalue)
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1205, u'Lock wait timeout exceeded; try restarting transaction')
2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] update failed
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource Traceback (most recent call last):
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 84, in resource
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result = method(request=request, **args)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 579, in update
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return self._update(request, id, body, **kwargs)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ectxt.value = e.inner_exc
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self.force_reraise()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return f(*args, **kwargs)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 624, in _update
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 912, in update_subnet
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context, id, subnet)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 764, in update_subnet
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     db_pools)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/ipam_pluggable_backend.py", line 381, in update_db_subnet
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._ipam_update_allocation_pools(context, ipam_driver, subnet_copy)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/ipam_pluggable_backend.py", line 159, in _ipam_update_allocation_pools
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ipam_driver.update_subnet(subnet_request)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 440, in update_subnet
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     subnet.update_allocation_pools(subnet_request.allocation_pools, cidr)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 377, in update_allocation_pools
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self.subnet_manager.delete_allocation_pools(session)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/db_api.py", line 99, in delete_allocation_pools
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ipam_subnet_id=self._ipam_subnet_id).delete()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 3048, in delete
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     delete_op.exec_()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1127, in exec_
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._do_exec()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1311, in _do_exec
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     mapper=self.mapper)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1034, in execute
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     bind, close_with_result=True).execute(clause, params or {})
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return meth(self, multiparams, params)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     compiled_sql, distilled_params
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     cursor.execute(statement, parameters)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result = self._query(query)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     conn.query(q)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result.read()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     first_packet = self.connection._read_packet()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     packet.check_error()
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     err.raise_mysql_exception(self._data)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     _check_mysql_exception(errinfo)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     raise InternalError(errno, errorvalue)
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource DBError: (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'DELETE FROM ipamallocationpools WHERE ipamallocationpools.ipam_subnet_id = %(ipam_subnet_id_1)s'] [parameters: {u'ipam_subnet_id_1': u'0b896671-8cc2-4e08-bbfe-05655e6c479c'}]
2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource
2016-04-19 15:43:05.863 17992 INFO neutron.wsgi [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] 127.0.0.1 - - [19/Apr/2016 15:43:05] "PUT /v2.0/subnets/f5613ce4-2fd8-4ab7-a87e-558b1b1b7bc2 HTTP/1.1" 500 363 51.651743
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters [req-ccd11684-ad2b-4937-a3c1-dc46aaa36b2d - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'INSERT INTO ipallocations (port_id, ip_address, subnet_id, network_id) VALUES (%(port_id)s, %(ip_address)s, %(subnet_id)s, %(network_id)s)'] [parameters: {'subnet_id': u'f5613ce4-2fd8-4ab7-a87e-558b1b1b7bc2', 'network_id': u'33d94f9c-e24b-448f-900c-0249fbd6c96d', 'port_id': 'b81c0244-1eb9-4716-b85f-253deed19b19', 'ip_address': u'2003::3'}]
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     context)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     _check_mysql_exception(errinfo)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     raise InternalError(errno, errorvalue)
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1205, u'Lock wait timeout exceeded; try restarting transaction')
2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters

** Affects: neutron
     Importance: Undecided
     Assignee: Pavel Bondar (pasha117)
         Status: New


** Tags: l3-ipam-dhcp

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

Title:
  [Pluggable IPAM] Deadlock on simultaneous update subnet and ip
  allocation from subnet

Status in neutron:
  New

Bug description:
  Observed in logs 'Lock wait timeout exceeded; try restarting transaction' [1], when two requests are concurently executed in neutron:
  - request A calls update subnet req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3
  - request B calls create port on the same subnet req-ccd11684-ad2b-4937-a3c1-dc46aaa36b2d
  As a result both requests  failed.

  Request A tries to delete 'ipamallocationpools' for subnet_id and it effectivelly removes 'ipamavailabilityranges' by foreign key.
  Request B allocates ip and modifies av_range record in 'ipamavailabilityranges'.
  So looks like collision caused by concurent access to 'ipamavailabilityranges' table.

  [1] http://logs.openstack.org/23/181023/68/check/gate-tempest-dsvm-
  neutron-full/a9180e0/logs/screen-q-svc.txt.gz#_2016-04-19_15_43_05_837

  StackTrace with both requests failed:
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'DELETE FROM ipamallocationpools WHERE ipamallocationpools.ipam_subnet_id = %(ipam_subnet_id_1)s'] [parameters: {u'ipam_subnet_id_1': u'0b896671-8cc2-4e08-bbfe-05655e6c479c'}]
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     context)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     _check_mysql_exception(errinfo)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters     raise InternalError(errno, errorvalue)
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1205, u'Lock wait timeout exceeded; try restarting transaction')
  2016-04-19 15:43:05.837 17992 ERROR oslo_db.sqlalchemy.exc_filters
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] update failed
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource Traceback (most recent call last):
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 84, in resource
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result = method(request=request, **args)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 579, in update
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return self._update(request, id, body, **kwargs)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ectxt.value = e.inner_exc
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self.force_reraise()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return f(*args, **kwargs)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 624, in _update
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 912, in update_subnet
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context, id, subnet)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 764, in update_subnet
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     db_pools)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/ipam_pluggable_backend.py", line 381, in update_db_subnet
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._ipam_update_allocation_pools(context, ipam_driver, subnet_copy)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/ipam_pluggable_backend.py", line 159, in _ipam_update_allocation_pools
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ipam_driver.update_subnet(subnet_request)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 440, in update_subnet
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     subnet.update_allocation_pools(subnet_request.allocation_pools, cidr)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 377, in update_allocation_pools
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self.subnet_manager.delete_allocation_pools(session)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/ipam/drivers/neutrondb_ipam/db_api.py", line 99, in delete_allocation_pools
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     ipam_subnet_id=self._ipam_subnet_id).delete()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 3048, in delete
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     delete_op.exec_()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1127, in exec_
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._do_exec()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1311, in _do_exec
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     mapper=self.mapper)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1034, in execute
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     bind, close_with_result=True).execute(clause, params or {})
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return meth(self, multiparams, params)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     compiled_sql, distilled_params
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb, cause=cause)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     context)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     cursor.execute(statement, parameters)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result = self._query(query)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     conn.query(q)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     result.read()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     first_packet = self.connection._read_packet()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     packet.check_error()
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     err.raise_mysql_exception(self._data)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     _check_mysql_exception(errinfo)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource     raise InternalError(errno, errorvalue)
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource DBError: (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'DELETE FROM ipamallocationpools WHERE ipamallocationpools.ipam_subnet_id = %(ipam_subnet_id_1)s'] [parameters: {u'ipam_subnet_id_1': u'0b896671-8cc2-4e08-bbfe-05655e6c479c'}]
  2016-04-19 15:43:05.847 17992 ERROR neutron.api.v2.resource
  2016-04-19 15:43:05.863 17992 INFO neutron.wsgi [req-5f9fc363-4b22-48e0-97e2-504aa7c3dda3 tempest-NetworksIpV6Test-714183411 -] 127.0.0.1 - - [19/Apr/2016 15:43:05] "PUT /v2.0/subnets/f5613ce4-2fd8-4ab7-a87e-558b1b1b7bc2 HTTP/1.1" 500 363 51.651743
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters [req-ccd11684-ad2b-4937-a3c1-dc46aaa36b2d - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1205, u'Lock wait timeout exceeded; try restarting transaction') [SQL: u'INSERT INTO ipallocations (port_id, ip_address, subnet_id, network_id) VALUES (%(port_id)s, %(ip_address)s, %(subnet_id)s, %(network_id)s)'] [parameters: {'subnet_id': u'f5613ce4-2fd8-4ab7-a87e-558b1b1b7bc2', 'network_id': u'33d94f9c-e24b-448f-900c-0249fbd6c96d', 'port_id': 'b81c0244-1eb9-4716-b85f-253deed19b19', 'ip_address': u'2003::3'}]
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     context)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     _check_mysql_exception(errinfo)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters     raise InternalError(errno, errorvalue)
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1205, u'Lock wait timeout exceeded; try restarting transaction')
  2016-04-19 15:43:05.862 17994 ERROR oslo_db.sqlalchemy.exc_filters

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

[Bug 1572474] Re: [Pluggable IPAM] Deadlock on simultaneous update subnet and ip allocation from subnet
From: OpenStack Infra, 2016-05-18