| Summary: | Trace errors during rally task create_and_delete_routers.json | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | Eran Kuris <ekuris> | ||||
| Component: | openstack-neutron | Assignee: | Ihar Hrachyshka <ihrachys> | ||||
| Status: | CLOSED ERRATA | QA Contact: | Toni Freger <tfreger> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | medium | ||||||
| Version: | 7.0 (Kilo) | CC: | amuller, chrisw, ekuris, hmlnarik, jschwarz, majopela, mlopes, nyechiel, srevivo | ||||
| Target Milestone: | async | Keywords: | ZStream | ||||
| Target Release: | 7.0 (Kilo) | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | openstack-neutron-2015.1.4-12.el7ost | Doc Type: | Bug Fix | ||||
| Doc Text: |
Prior to this update, data database layer errors were not caught by the server component, resulting in errors during port status update requests (for particular race conditions). Consequently, on occasion, an L2 agent that attempted to update a port status could have caught an unexpected error from neutron-server, triggering a costly full resync of port data.
With this update, neutron-server now correctly catches the previously missed error and repeats the failed operation.
As a result, the L2 agent is no longer exposed to the unexpected error, and will not trigger full resync in this particular scenario.
|
Story Points: | --- | ||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2017-02-15 13:50:35 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Attachments: |
|
||||||
Created attachment 1193544 [details]
logs
Was there any impact of the trace? Has anything failed? The rally tests showed 100% success rate for 'rally task detailed' of that run, and no ports were left afterwards. I didn't find any other side effects as well, though you might have better ideas. Looks like if a the status of a port is concurrently updated from two places, and 2nd fails. I'd like to have a look on the ovs agent which called that get_devices_details_list (which in turns triggers the port update). Seeing 100% success on the test, I assume that the ovs-agent gets the failed call and triggers a full-sync with the server, recovering from the condition. The StaleDataError issue is harmless and seems same as bug 1348998. See there for details, namely comments 2 and 3. The StaleDataError impact was mitigated in liberty by retrying the operation. The code is verified on latest OSP7 - openstack-neutron-2015.1.4-12.el7ost.noarch Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2017-0277.html |
Description of problem: Ran rally task on RHOS7 HA env in neutron server log I found those trace errors 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last): 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher executor_callback)) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher executor_callback) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/rpc.py", line 134, in get_devices_details_list 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher for device in kwargs.pop('devices', []) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/rpc.py", line 106, in get_device_details 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher host) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 131, in wrapper 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py", line 1388, in update_port_status 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher original_port['network_id']) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py", line 653, in get_network 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher result = super(Ml2Plugin, self).get_network(context, id, None) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 1022, in get_network 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher network = self._get_network(context, id) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py", line 91, in _get_network 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher network = self._get_by_id(context, models_v2.Network, id) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/db/common_db_mixin.py", line 171, in _get_by_id 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher return query.filter(model.id == id).one() 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2473, in one 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher ret = list(self) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2515, in __iter__ 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher self.session._autoflush() 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 1282, in _autoflush 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher self.flush() 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2004, in flush 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher self._flush(objects) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2122, in _flush 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher transaction.rollback(_capture_exception=True) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__ 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher compat.reraise(exc_type, exc_value, exc_tb) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2086, in _flush 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher flush_context.execute() 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher rec.execute(self) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher uow 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 170, in save_obj 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher mapper, table, update) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 712, in _emit_update_statements 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher (table.description, len(records), rows)) 2016-08-23 13:12:20.271 27891 TRACE oslo_messaging.rpc.dispatcher StaleDataError: UPDATE statement on table 'ports' expected to update 1 row(s); 0 were matched. Version-Release number of selected component (if applicable): openstack-neutron-2015.1.4-3.el7ost.noarch openstack-neutron-ml2-2015.1.4-3.el7ost.noarch python-neutron-2015.1.4-3.el7ost.noarch openstack-neutron-common-2015.1.4-3.el7ost.noarch openstack-neutron-openvswitch-2015.1.4-3.el7ost.noarch python-neutronclient-2.4.0-2.el7ost.noarch How reproducible: Steps to Reproduce: 1. deploy rhos 7 HA (virtual setup) 2. run rally test : create_and_delete_routers.json 3. check server log Actual results: Expected results: Additional info: