← Back to team overview

yahoo-eng-team team mailing list archive

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

[Bug 1333084] [NEW] test_update_port_with_second_ip failed due to a server failure “Caught error: (TransactionRollbackError) deadlock detected”

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

tempest.api.network.test_ports.PortsTestJSON.test_update_port_with_second_ip faild due
 to a deadlock in the db.

the trace below from the q-svc screen log appears to be very similar to
a similar open bug in the cinder project which suggest that this class
of intermitent deadlock may exist in other cases.

https://bugs.launchpad.net/cinder/+bug/1294855

full log avalable here 
http://logs.openstack.org/38/95138/8/check/check-tempest-dsvm-neutron-pg/99dc5cb/logs/


2014-06-21 18:07:30.852 21519 ERROR neutron.api.v2.resource [req-ac0f177d-9b3c-4ec7-9001-1f92dfd1bf16 None] update failed
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource Traceback (most recent call last):
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 87, in resource
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = method(request=request, **args)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 531, in update
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 682, in update_port
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     port)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 1497, in update_port
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     p['fixed_ips'])
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 650, in _update_ips_for_port
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     ips = self._allocate_fixed_ips(context, network, to_add)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 612, in _allocate_fixed_ips
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = self._generate_ip(context, subnets)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 364, in _generate_ip
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return NeutronDbPluginV2._try_generate_ip(context, subnets)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 381, in _try_generate_ip
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     range = range_qry.filter_by(subnet_id=subnet['id']).first()
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2333, in first
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     ret = list(self[0:1])
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2200, in __getitem__
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return list(res)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2404, in __iter__
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return self._execute_and_instances(context)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2419, in _execute_and_instances
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = conn.execute(querycontext.statement, self._params)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 720, in execute
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 317, in _execute_on_connection
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 817, in _execute_clauseelement
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 947, in _execute_context
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     context)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1108, in _handle_dbapi_exception
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     exc_info
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 185, in raise_from_cause
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 940, in _execute_context
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     context)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 435, in do_execute
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource DBAPIError: (TransactionRollbackError) deadlock detected
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource DETAIL:  Process 21690 waits for ShareLock on transaction 10397; blocked by process 21692.
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource Process 21692 waits for ShareLock on transaction 10396; blocked by process 21690.
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource HINT:  See server log for query details.
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource  'SELECT ipavailabilityranges.allocation_pool_id AS ipavailabilityranges_allocation_pool_id, ipavailabilityranges.first_ip AS ipavailabilityranges_first_ip, ipavailabilityranges.last_ip AS ipavailabilityranges_last_ip \nFROM ipavailabilityranges JOIN ipallocationpools ON ipallocationpools.id = ipavailabilityranges.allocation_pool_id \nWHERE ipallocationpools.subnet_id = %(subnet_id_1)s \n LIMIT %(param_1)s FOR UPDATE' {'param_1': 1, 'subnet_id_1': u'7dd0bab8-e96c-4a23-8603-c538239d112d'}
2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource 
2014-06-21 18:07:30.860 21519 INFO neutron.wsgi [req-ac0f177d-9b3c-4ec7-9001-1f92dfd1bf16 None] 127.0.0.1 - - [21/Jun/2014 18:07:30] "PUT /v2.0/ports/64563057-99d6-4f5e-8829-ffcc0e70bdb6 HTTP/1.1" 500 315 1.370053

** Affects: neutron
     Importance: Undecided
         Status: New

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

Title:
  test_update_port_with_second_ip failed due to a server failure “Caught
  error: (TransactionRollbackError) deadlock detected”

Status in OpenStack Neutron (virtual network service):
  New

Bug description:
  tempest.api.network.test_ports.PortsTestJSON.test_update_port_with_second_ip faild due
   to a deadlock in the db.

  the trace below from the q-svc screen log appears to be very similar
  to a similar open bug in the cinder project which suggest that this
  class of intermitent deadlock may exist in other cases.

  https://bugs.launchpad.net/cinder/+bug/1294855

  full log avalable here 
  http://logs.openstack.org/38/95138/8/check/check-tempest-dsvm-neutron-pg/99dc5cb/logs/

  
  2014-06-21 18:07:30.852 21519 ERROR neutron.api.v2.resource [req-ac0f177d-9b3c-4ec7-9001-1f92dfd1bf16 None] update failed
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource Traceback (most recent call last):
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 87, in resource
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = method(request=request, **args)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 531, in update
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 682, in update_port
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     port)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 1497, in update_port
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     p['fixed_ips'])
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 650, in _update_ips_for_port
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     ips = self._allocate_fixed_ips(context, network, to_add)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 612, in _allocate_fixed_ips
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = self._generate_ip(context, subnets)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 364, in _generate_ip
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return NeutronDbPluginV2._try_generate_ip(context, subnets)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 381, in _try_generate_ip
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     range = range_qry.filter_by(subnet_id=subnet['id']).first()
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2333, in first
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     ret = list(self[0:1])
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2200, in __getitem__
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return list(res)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2404, in __iter__
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return self._execute_and_instances(context)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2419, in _execute_and_instances
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     result = conn.execute(querycontext.statement, self._params)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 720, in execute
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 317, in _execute_on_connection
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 817, in _execute_clauseelement
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 947, in _execute_context
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     context)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1108, in _handle_dbapi_exception
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     exc_info
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 185, in raise_from_cause
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 940, in _execute_context
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     context)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 435, in do_execute
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource DBAPIError: (TransactionRollbackError) deadlock detected
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource DETAIL:  Process 21690 waits for ShareLock on transaction 10397; blocked by process 21692.
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource Process 21692 waits for ShareLock on transaction 10396; blocked by process 21690.
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource HINT:  See server log for query details.
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource  'SELECT ipavailabilityranges.allocation_pool_id AS ipavailabilityranges_allocation_pool_id, ipavailabilityranges.first_ip AS ipavailabilityranges_first_ip, ipavailabilityranges.last_ip AS ipavailabilityranges_last_ip \nFROM ipavailabilityranges JOIN ipallocationpools ON ipallocationpools.id = ipavailabilityranges.allocation_pool_id \nWHERE ipallocationpools.subnet_id = %(subnet_id_1)s \n LIMIT %(param_1)s FOR UPDATE' {'param_1': 1, 'subnet_id_1': u'7dd0bab8-e96c-4a23-8603-c538239d112d'}
  2014-06-21 18:07:30.852 21519 TRACE neutron.api.v2.resource 
  2014-06-21 18:07:30.860 21519 INFO neutron.wsgi [req-ac0f177d-9b3c-4ec7-9001-1f92dfd1bf16 None] 127.0.0.1 - - [21/Jun/2014 18:07:30] "PUT /v2.0/ports/64563057-99d6-4f5e-8829-ffcc0e70bdb6 HTTP/1.1" 500 315 1.370053

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

Follow ups

References

  Thread Previous • Date Previous • • Thread Next