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 -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
