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

-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to