Comment 0 for bug 1381536

Revision history for this message
Ian Ong (ongmichaelian) wrote : ResourceClosedError occurs when create_port from DHCP agent and create_port from neutron API run in parallel

When DHCP agent creates port from neutron and another create port request is received, ResourceClosedError occurs in sqlalchemy.

this may be related to bug #1282922 https://bugs.launchpad.net/bugs/1282922
Above bug is related to nec plugin and it is mentioned that other plugins may be affected.
This error occurred in ML2 plugin both for create and delete ports.
Tested using 2014.3 Icehouse

   Neutron User Neutron DHCP Agent
       | | |
       | | DHCP VPort |
       | | Create Port Req |
       | |<-------------------|
       | VPort | |
       | Create Port Req | |
       |------------------->| |
       | |* Conflict |
       | | |
       | | |
       | | Create Port Resp |
       | |------------------->|
       | Create Port Resp | |
       | *Error Response | |
       |<-------------------| |
       | | |
       | | |

2014-10-15 21:58:59.837 26167 INFO neutron.wsgi [-] (26167) accepted ('172.16.2.86', 47007)

2014-10-15 21:58:59.870 26167 INFO neutron.wsgi [req-424a01ca-f52b-43a6-8844-d0d3590feb8d None] 172.16.2.86 - - [15/Oct/2014 21:58:59] "GET /v2.0/networks.json?fields=id&name=testnw2 HTTP/1.1" 200 251 0.031936

2014-10-15 21:58:59.872 26167 INFO neutron.wsgi [req-424a01ca-f52b-43a6-8844-d0d3590feb8d None] (26167) accepted ('172.16.2.86', 47008)

2014-10-15 21:58:59.950 26167 INFO neutron.wsgi [req-7ee742ef-6370-46b3-8f8b-f46ae5d262bc None] 172.16.2.86 - - [15/Oct/2014 21:58:59] "POST /v2.0/subnets.json HTTP/1.1" 201 572 0.076879

2014-10-15 21:59:00.074 26167 INFO neutron.wsgi [req-a6ef6c65-811f-40d8-9443-b9590809994a None] (26167) accepted ('172.16.2.86', 47010)

2014-10-15 21:59:00.088 26167 INFO urllib3.connectionpool [-] Starting new HTTPS connection (1): 10.68.42.86
2014-10-15 21:59:00.111 26167 INFO neutron.wsgi [req-22a84d34-f454-423d-bb7b-b4c7e2e6e08c None] 172.16.2.86 - - [15/Oct/2014 21:59:00] "GET /v2.0/networks.json?fields=id&name=testnw2 HTTP/1.1" 200 251 0.033298

2014-10-15 21:59:00.113 26167 INFO neutron.wsgi [req-22a84d34-f454-423d-bb7b-b4c7e2e6e08c None] (26167) accepted ('172.16.2.86', 47012)

2014-10-15 21:59:51.165 26167 ERROR neutron.api.v2.resource [-] create failed
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource Traceback (most recent call last):
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/api/v2/resource.py", line 87, in resource
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource result = method(request=request, **args)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/api/v2/base.py", line 448, in create
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource obj = obj_creator(request.context, **kwargs)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py", line 632, in create_port
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource result = super(Ml2Plugin, self).create_port(context, port)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 1371, in create_port
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource ips = self._allocate_ips_for_port(context, network, port)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 678, in _allocate_ips_for_port
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource result = NeutronDbPluginV2._generate_ip(context, subnets)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 359, in _generate_ip
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource return NeutronDbPluginV2._try_generate_ip(context, subnets)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 376, in _try_generate_ip
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource range = range_qry.filter_by(subnet_id=subnet['id']).first()
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2282, in first
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource ret = list(self[0:1])
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2149, in __getitem__
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource return list(res)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/loading.py", line 65, in instances
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource fetch = cursor.fetchall()
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/result.py", line 752, in fetchall
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource self.cursor, self.context)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1027, in _handle_dbapi_exception
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource util.reraise(*exc_info)
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/result.py", line 746, in fetchall
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource l = self.process_rows(self._fetchall_impl())
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/result.py", line 715, in _fetchall_impl
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource self._non_result()
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/result.py", line 720, in _non_result
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource "This result object does not return rows. "
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource ResourceClosedError: This result object does not return rows. It has been closed automatically.
2014-10-15 21:59:51.165 26167 TRACE neutron.api.v2.resource
2014-10-15 21:59:51.167 26167 INFO neutron.wsgi [-] 172.16.2.86 - - [15/Oct/2014 21:59:51] "POST /v2.0/ports.json HTTP/1.1" 500 296 51.052950