DBDeadlock occurs when delete router_gateway

Bug #1718369 reported by Zachary Ma
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
neutron
Confirmed
Undecided
Unassigned

Bug Description

I have 3 controllers and each controllers are running neutron-server. When I delete router_gateway, some of the controllers occasionally crash with DBDeadlock exceptions:

69597:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager [req-31af8910-b348-49c4-9082-8647f1ef94ca 0c806b3af06b4025ad180a6d6213d02c 9d120e49c3e2484b827597bdde57f850 - default default] Error during notification for neutron.services.l3_router.l3_router_plugin.L3RouterPlugin._delete_dvr_internal_ports--9223372036852560901 router_gateway, after_delete: DBDeadlock: (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'DELETE FROM portsecuritybindings WHERE portsecuritybindings.port_id = %(port_id)s'] [parameters: {'port_id': u'f7dea1fa-5436-4a43-b0ec-0bef99371375'}]
69598:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager Traceback (most recent call last):
69599:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py", line 171, in _notify_loop
69600:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager callback(resource, event, trigger, **kwargs)
69601:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/db/l3_dvr_db.py", line 272, in _delete_dvr_internal_ports
69602:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager context.elevated(), None, network_id)
69603:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/db/l3_dvr_db.py", line 288, in delete_floatingip_agent_gateway_port
69604:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self._core_plugin.ipam.delete_port(context, p['id'])
69605:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/db/ipam_pluggable_backend.py", line 429, in delete_port
69606:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager port['fixed_ips'])
69607:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/db/ipam_pluggable_backend.py", line 95, in _ipam_deallocate_ips
69608:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager "external system for %s", addresses)
69609:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
69610:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self.force_reraise()
69611:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
69612:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager six.reraise(self.type_, self.value, self.tb)
69613:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/db/ipam_pluggable_backend.py", line 71, in _ipam_deallocate_ips
69614:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager ipam_subnet = ipam_driver.get_subnet(ip['subnet_id'])
69615:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 267, in get_subnet
69616:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager return NeutronDbSubnet.load(subnet_id, self._context)
69617:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/ipam/drivers/neutrondb_ipam/driver.py", line 91, in load
69618:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager ctx, neutron_subnet_id)
69619:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/ipam/drivers/neutrondb_ipam/db_api.py", line 30, in load_by_neutron_subnet_id
69620:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager context, neutron_subnet_id=neutron_subnet_id)
69621:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/neutron/objects/base.py", line 463, in get_objects
69622:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager with context.session.begin(subtransactions=True):
69623:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 824, in begin
69624:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self, nested=nested)
69625:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 218, in __init__
69626:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self._take_snapshot()
69627:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 327, in _take_snapshot
69628:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self.session.flush()
69629:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2171, in flush
69630:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self._flush(objects)
69631:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2291, in _flush
69632:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager transaction.rollback(_capture_exception=True)
69633:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
69634:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager compat.reraise(exc_type, exc_value, exc_tb)
69635:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2255, in _flush
69636:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager flush_context.execute()
69637:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 389, in execute
69638:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager rec.execute(self)
69639:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 577, in execute
69640:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager uow
69641:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 258, in delete_obj
69642:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager cached_connections, mapper, table, delete)
69643:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 931, in _emit_delete_statements
69644:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager c = connection.execute(statement, del_objects)
69645:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 945, in execute
69646:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager return meth(self, multiparams, params)
69647:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 263, in _execute_on_connection
69648:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager return connection._execute_clauseelement(self, multiparams, params)
69649:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1053, in _execute_clauseelement
69650:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager compiled_sql, distilled_params
69651:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1189, in _execute_context
69652:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager context)
69653:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1398, in _handle_dbapi_exception
69654:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager util.raise_from_cause(newraise, exc_info)
69655:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
69656:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager reraise(type(exception), exception, tb=exc_tb, cause=cause)
69657:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
69658:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager context)
69659:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
69660:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager cursor.execute(statement, parameters)
69661:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
69662:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager result = self._query(query)
69663:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
69664:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager conn.query(q)
69665:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
69666:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager self._affected_rows = self._read_query_result(unbuffered=unbuffered)
69667:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
69668:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager result.read()
69669:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
69670:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager first_packet = self.connection._read_packet()
69671:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
69672:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager packet.check_error()
69673:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
69674:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager err.raise_mysql_exception(self._data)
69675:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
69676:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager raise errorclass(errno, errval)
69677:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager DBDeadlock: (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'DELETE FROM portsecuritybindings WHERE portsecuritybindings.port_id = %(port_id)s'] [parameters: {'port_id': u'f7dea1fa-5436-4a43-b0ec-0bef99371375'}]
69678:2017-09-20 10:58:10.606 2114 ERROR neutron_lib.callbacks.manager

Zachary Ma (mazengxie)
tags: added: neutron
summary: - DBDeadlock
+ DBDeadlock occurs when delete router_gateway
Revision history for this message
Brian Haley (brian-haley) wrote :

Can you give more info, like what version of Neutron this is? Thanks.

Changed in neutron:
status: New → Incomplete
tags: added: l3-ipam-dhcp
Revision history for this message
Zachary Ma (mazengxie) wrote :

openstack version: pike
neutron version: 6.5.0
[root@172e18e211e96 ~]# neutron --version
6.5.0

Zachary Ma (mazengxie)
Changed in neutron:
status: Incomplete → Confirmed
Revision history for this message
Joe D'Andrea (jdandrea) wrote :
Download full text (29.5 KiB)

I'm sporadically experiencing a DBDeadlock as well. It doesn't necessarily happen when deleting a network. Here's an example. Note that there's a DBDeadlock immediately followed by a DBReferenceError (perhaps not surprising given the deadlock).

2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager [req-347d9855-d768-45e9-8a57-33b8a07b1b1f 5c643c834f344f26bfeda1f6cae2b6e8 d40c5288f967411dbc74235714520592 - - -] Error during notification for neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification--9223372036851838000 port, after_create
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager Traceback (most recent call last):
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/callbacks/manager.py", line 146, in _notify_loop
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager callback(resource, event, trigger, **kwargs)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 245, in _native_event_send_dhcp_notification
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager self.notify(context, data, method_name)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 283, in notify
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager self._notify_agents(context, method_name, data, network_id)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 183, in _notify_agents
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager agents = self._schedule_network(admin_ctx, network, agents)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 101, in _schedule_network
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager new_agents = self.plugin.schedule_network(context, network) or []
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/db/agentschedulers_db.py", line 572, in schedule_network
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager self, context, created_network)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/scheduler/base_scheduler.py", line 43, in schedule
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager plugin, context, resource)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/scheduler/dhcp_agent_scheduler.py", line 214, in filter_agents
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager plugin, context, network)
2017-10-30 17:56:10.831 13 ERROR neutron.callbacks.manager File "/var/lib/kolla...

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.