← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1943714] [NEW] DB session commit error in resource_registry.set_resources_dirty

 

Public bug reported:

It seems that patch
https://review.opendev.org/c/openstack/neutron/+/805031 introduced some
new error during call of resource_registry.set_resources_dirty() in
https://github.com/openstack/neutron/blob/6db261962894b1667dd213b116e89246a3e54386/neutron/api/v2/base.py#L506

I didn't saw that issue in our CI jobs on master branch but we noticed
them in the d/s jobs on OSP-16 which is based on Train. Error is like:

2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                              [731/1883]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper                                                                                                                                          
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     return f(*args, **kwargs)                                                                                                                                                                                           
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped                                                                                                                                   
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     LOG.debug("Retry wrapper got retriable exception: %s", e)                                                                                                                                                           
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__                                                                                                                                 
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.force_reraise()                                                                                                                                                                                                
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise                                                                                                                            
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                                        
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 179, in wrapped                                                                                                                                   
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     return f(*dup_args, **dup_kwargs)                                                                                                                                                                                   
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 558, in _create                                                                                                                                  
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     obj)})                                                                                                                                                                                                              
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 500, in notify                                                                                                                                   
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     resource_registry.set_resources_dirty(request.context)                                                                                                                                                              
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__                                                                                                                                                       
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     next(self.gen)                                                                                                                                                                                                      
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1065, in _transaction_scope                                                                                                          
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     yield resource                                                                                                                                                                                                      
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__                                                                                                                                                       
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     next(self.gen)                                                                                                                                                                                                      
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 667, in _session                                                                                                                     
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.session.rollback()                                                                                                                                                                                             
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__                                                                                                                                 
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.force_reraise()                                                                                                                                                                                                
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise                                                                                                                            
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                                        
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 664, in _session                                                                                                                     
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self._end_session_transaction(self.session)                                                                                                                                                                         
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 692, in _end_session_transaction                                                                                                     
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     session.commit()                                                                                                                                                                                                    
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1026, in commit                                                                                                                             
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.transaction.commit()                                                                                                                                                                                           
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 491, in commit                                                                                                                              
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self._assert_active(prepared_ok=True)                                                                                                                                                                               
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 294, in _assert_active                                                                                                                      
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     % self._rollback_exception                                                                                                                                                                                          
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original ex$
eption was: (pymysql.err.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')                                                                                                                                                          
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [SQL: DELETE FROM reservations WHERE reservations.id = %(id)s]                                                                                                                
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [parameters: {'id': '3644bc07-a2b6-47b2-9767-bbf89f9606e2'}]                                                                                                                                                            
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/e3q8)                                                                                            

I guess that this may be some race condition which can be hit under
specific conditions and IMHO it can happend also in master branch as
well.

** Affects: neutron
     Importance: High
     Assignee: Slawek Kaplonski (slaweq)
         Status: New


** Tags: db

** Changed in: neutron
     Assignee: (unassigned) => Slawek Kaplonski (slaweq)

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1943714

Title:
  DB session commit error in resource_registry.set_resources_dirty

Status in neutron:
  New

Bug description:
  It seems that patch
  https://review.opendev.org/c/openstack/neutron/+/805031 introduced
  some new error during call of resource_registry.set_resources_dirty()
  in
  https://github.com/openstack/neutron/blob/6db261962894b1667dd213b116e89246a3e54386/neutron/api/v2/base.py#L506

  I didn't saw that issue in our CI jobs on master branch but we noticed
  them in the d/s jobs on OSP-16 which is based on Train. Error is like:

  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                              [731/1883]
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper                                                                                                                                          
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     return f(*args, **kwargs)                                                                                                                                                                                           
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped                                                                                                                                   
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     LOG.debug("Retry wrapper got retriable exception: %s", e)                                                                                                                                                           
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__                                                                                                                                 
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.force_reraise()                                                                                                                                                                                                
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise                                                                                                                            
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                                        
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 179, in wrapped                                                                                                                                   
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     return f(*dup_args, **dup_kwargs)                                                                                                                                                                                   
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 558, in _create                                                                                                                                  
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     obj)})                                                                                                                                                                                                              
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 500, in notify                                                                                                                                   
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     resource_registry.set_resources_dirty(request.context)                                                                                                                                                              
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__                                                                                                                                                       
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     next(self.gen)                                                                                                                                                                                                      
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1065, in _transaction_scope                                                                                                          
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     yield resource                                                                                                                                                                                                      
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__                                                                                                                                                       
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     next(self.gen)                                                                                                                                                                                                      
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 667, in _session                                                                                                                     
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.session.rollback()                                                                                                                                                                                             
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__                                                                                                                                 
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.force_reraise()                                                                                                                                                                                                
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise                                                                                                                            
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)                                                                                                                                                                        
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise                                                                                                                                                  
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     raise value                                                                                                                                                                                                         
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 664, in _session                                                                                                                     
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self._end_session_transaction(self.session)                                                                                                                                                                         
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 692, in _end_session_transaction                                                                                                     
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     session.commit()                                                                                                                                                                                                    
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1026, in commit                                                                                                                             
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self.transaction.commit()                                                                                                                                                                                           
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 491, in commit                                                                                                                              
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     self._assert_active(prepared_ok=True)                                                                                                                                                                               
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 294, in _assert_active                                                                                                                      
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource     % self._rollback_exception                                                                                                                                                                                          
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original ex$
  eption was: (pymysql.err.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')                                                                                                                                                          
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [SQL: DELETE FROM reservations WHERE reservations.id = %(id)s]                                                                                                                
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [parameters: {'id': '3644bc07-a2b6-47b2-9767-bbf89f9606e2'}]                                                                                                                                                            
  2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/e3q8)                                                                                            

  I guess that this may be some race condition which can be hit under
  specific conditions and IMHO it can happend also in master branch as
  well.

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1943714/+subscriptions



Follow ups