Bug 1487783 - StaleDataError on run_sync_thread
Summary: StaleDataError on run_sync_thread
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: python-networking-odl
Version: 12.0 (Pike)
Hardware: Unspecified
OS: Unspecified
medium
low
Target Milestone: beta
: 13.0 (Queens)
Assignee: Michel Peterson
QA Contact: Toni Freger
URL:
Whiteboard: scale_lab
: 1512085 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-09-01 22:03 UTC by Sai Sindhur Malleni
Modified: 2018-10-24 12:37 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
N/A
Last Closed: 2018-03-27 09:16:37 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
OpenStack gerrit 500584 0 None master: MERGED networking-odl: Fixes error handling of DB calls (I31085cf73618df48f55f3169e071d2cb64c9b018) 2018-03-21 13:34:23 UTC

Description Sai Sindhur Malleni 2017-09-01 22:03:18 UTC 
Description of problem: When running a Browbeat+Rally use case which does:
Create a network
Create a sbunet
Create a router
Attach router to subnet and oublic network
Boot VM with floating IP
Ping VM

with concurrency 8 and times set to 50 we see that some VMs remain unpingable even after 300 seconds and we see a lot of the following in neutron server logs:


2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal [req-26da4c47-f34c-460e-9692-9ee45828fccc - - - - -] Error on run_sync_thread: StaleDataError: UPDATE statement on table 'opendaylightjournal' expected to update 1 row(s); 0 were matched.
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal Traceback (most recent call last):
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/networking_odl/journal/journal.py", line 206, in run_sync_thread
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.sync_pending_entries()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/networking_odl/journal/journal.py", line 224, in sync_pending_entries
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     entry = db.get_oldest_pending_db_row_with_lock(context.session)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/neutron/db/api.py", line 94, in wrapped
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     setattr(e, '_RETRY_EXCEEDED', True)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.force_reraise()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     six.reraise(self.type_, self.value, self.tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/neutron/db/api.py", line 90, in wrapped
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     return f(*args, **kwargs)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 150, in wrapper
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     ectxt.value = e.inner_exc
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.force_reraise()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     six.reraise(self.type_, self.value, self.tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     return f(*args, **kwargs)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/neutron/db/api.py", line 129, in wrapped
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     LOG.debug("Retry wrapper got retriable exception: %s", e)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.force_reraise()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     six.reraise(self.type_, self.value, self.tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     return f(*args, **kwargs)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/neutron/db/api.py", line 129, in wrapped
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     LOG.debug("Retry wrapper got retriable exception: %s", e)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.force_reraise()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     six.reraise(self.type_, self.value, self.tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/neutron/db/api.py", line 125, in wrapped
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     return f(*dup_args, **dup_kwargs)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/networking_odl/db/db.py", line 89, in get_oldest_pending_db_row_with_lock
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     update_db_row_state(session, row, odl_const.PROCESSING)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 150, in wrapper
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     ectxt.value = e.inner_exc
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.force_reraise()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     six.reraise(self.type_, self.value, self.tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     return f(*args, **kwargs)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib/python2.7/site-packages/networking_odl/db/db.py", line 106, in update_db_row_state
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     session.merge(row)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 1839, in merge
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self._autoflush()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 1397, in _autoflush
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self.flush()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2171, in flush
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     self._flush(objects)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2291, in _flush
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     transaction.rollback(_capture_exception=True)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     compat.reraise(exc_type, exc_value, exc_tb)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2255, in _flush
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     flush_context.execute()
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 389, in execute
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     rec.execute(self)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 548, in execute
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     uow
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     mapper, table, update)
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 760, in _emit_update_statements
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal     (table.description, len(records), rows))
2017-09-01 14:02:20.570 90871 ERROR networking_odl.journal.journal StaleDataError: UPDATE statement on table 'opendaylightjournal' expected to update 1 row(s); 0 were matched.
 

Version-Release number of selected component (if applicable):
OSP12+ODL Carbon
python-networking-odl-11.0.0-0.20170806093629.2e78dca.el7ost.noarch


How reproducible:
100%

Steps to Reproduce:
1. Deploy overcloud with ODL
2. Run custom Browbeat+Rally plugin which boots vm nad ping sfloatingip
3. 

Actual results:
Tracebacks in neutron server logs

Expected results:
No tracebacks in neut
Comment 1 Mike Kolesnik 2017-09-19 13:18:46 UTC 
This needs to be cleared from the log probably, the error itself is harmless and not related to the unpingable VMs (it's a race to get the next journal entry)
Comment 2 Michel Peterson 2017-10-15 14:48:11 UTC 
The bug itself is related to incorrect handling of DB transactions, as a new transaction is not created, after rolling back the previous one, the result is always the same error. This should be fixed with https://review.openstack.org/500584 once it's accepted.

As the patch itself is quite extensive it would be advisable to wait until it has been reviewed and merged to re-assess the status of this bug. In the meanwhile, as Mike explained, this error is harmless and therefore it can remain in a low priority.
Comment 5 Mike Kolesnik 2018-02-19 11:36:46 UTC 
*** Bug 1512085 has been marked as a duplicate of this bug. ***
Comment 9 Nir Yechiel 2018-03-27 09:16:37 UTC 
Closing as per conversation with Itzik and Mike.
Note You need to log in before you can comment on or make changes to this bug.