Lock wait timeout exceeded while updating router

Bug #1522219 reported by Jerry Zhao
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
networking-fortinet
New
Undecided
Unassigned

Bug Description

http://10.160.2.223:8081/logs/46/2/devstack-tempest-fortinet-vm-aio/26/logs/screen-q-svc.txt.gz

2015-12-02 16:15:00.587 32188 DEBUG neutron.db.db_base_plugin_v2 [req-76645e4a-f741-4334-8c5d-edb13c7fa4d5 None] Generated mac for network 063d664c-95a7-4cf3-9bc3-5ea66645e2b5 is fa:16:3e:8d:3b:1c _generate_mac /opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py:144
2015-12-02 16:15:51.719 32188 ERROR neutron.api.v2.resource [req-76645e4a-f741-4334-8c5d-edb13c7fa4d5 None] update failed
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource Traceback (most recent call last):
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 87, in resource
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource result = method(request=request, **args)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 538, in update
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource obj = obj_updater(request.context, id, **kwargs)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/services/l3_router/l3_fortinet.py", line 93, in update_router
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource update_router(context, id, router)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/extraroute_db.py", line 75, in update_router
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource context, id, router)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_db.py", line 1126, in update_router
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource id, router)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_db.py", line 193, in update_router
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource self._update_router_gw_info(context, id, gw_info)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_gwmode_db.py", line 66, in _update_router_gw_info
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource context, router_id, info, router=router)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_db.py", line 346, in _update_router_gw_info
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource self._create_gw_port(context, router_id, router, network_id)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_dvr_db.py", line 117, in _create_gw_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource router, new_network)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_db.py", line 336, in _create_gw_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource self._create_router_gw_port(context, router, new_network)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/l3_db.py", line 278, in _create_router_gw_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource 'name': ''}})
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 799, in create_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource result = super(Ml2Plugin, self).create_port(context, port)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 1364, in create_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource ips = self._allocate_ips_for_port(context, port)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 586, in _allocate_ips_for_port
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource result = NeutronDbPluginV2._generate_ip(context, subnets)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 199, in _generate_ip
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource return NeutronDbPluginV2._try_generate_ip(context, subnets)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/db/db_base_plugin_v2.py", line 216, in _try_generate_ip
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource ip_range = range_qry.filter_by(subnet_id=subnet['id']).first()
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2282, in first
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource ret = list(self[0:1])
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2149, in __getitem__
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource return list(res)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2353, in __iter__
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource return self._execute_and_instances(context)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2368, in _execute_and_instances
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource result = conn.execute(querycontext.statement, self._params)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource params)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource compiled_sql, distilled_params
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource context)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/compat/handle_error.py", line 125, in _handle_dbapi_exception
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource six.reraise(type(newraise), newraise, sys.exc_info()[2])
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/compat/handle_error.py", line 102, in _handle_dbapi_exception
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource per_fn = fn(ctx)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/exc_filters.py", line 323, in handler
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource context.is_disconnect)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/exc_filters.py", line 254, in _raise_operational_errors_directly_filter
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource raise operational_error
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') '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 INNER JOIN ipallocationpools ON ipallocationpools.id = ipavailabilityranges.allocation_pool_id \nWHERE ipallocationpools.subnet_id = %s \n LIMIT %s FOR UPDATE' ('9b78ce09-dff2-44a1-a57a-02eae72b207e', 1)
2015-12-02 16:15:51.719 32188 TRACE neutron.api.v2.resource
2015-12-02 16:15:51.746 32188 INFO neutron.wsgi [req-76645e4a-f741-4334-8c5d-edb13c7fa4d5 None] 127.0.0.1 - - [02/Dec/2015 16:15:51] "PUT /v2.0/routers/74c9bfdf-f6aa-4de0-918d-f90930373165 HTTP/1.1" 500 378 51.285187
2015-12-02 16:15:51.747 32188 DEBUG neutron.plugins.ml2.drivers.fortinet.api_client.base [-] [534] Acquired connection https://10.160.2.225:443. 0 connection(s) available. acquire_connection /opt/stack/new/neutron/neutron/plugins/ml2/drivers/fortinet/api_client/base.py:140
2015-12-02 16:15:51.748 32188 DEBUG neutron.plugins.ml2.drivers.fortinet.api_client.request [-] [534] Issuing - request url: POST https://10.160.2.225:443/api/v2/cmdb/system/vdom-link/, body: {u'json': {u'name': u'osvdm7_'}, u'name': u'vdom-link'} _issue_request /opt/stack/new/neutron/neutron/plugins/ml2/drivers/fortinet/api_client/request.py:91

Revision history for this message
Jerry Zhao (zhaoxinyu) wrote :
Revision history for this message
Sam Su (sam-su) wrote :

This issue is caused by a up-streaming commit, and the commit fixed now.

Changed in networking-fortinet:
status: New → Invalid
Revision history for this message
Jerry Zhao (zhaoxinyu) wrote :

i think you are talking about this one https://bugs.launchpad.net/neutron/+bug/1529022
but the bug here is different.

Changed in networking-fortinet:
status: Invalid → New
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.