Bug 1661927
| Summary: | [Driver] networking_odl InvalidRequestError: Object is already attached to session (False Error) | ||
|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | Noam Manos <nmanos> |
| Component: | python-networking-odl | Assignee: | Michel Peterson <mpeterso> |
| Status: | CLOSED WONTFIX | QA Contact: | Noam Manos <nmanos> |
| Severity: | medium | Docs Contact: | |
| Priority: | low | ||
| Version: | 14.0 (Rocky) | Keywords: | Triaged, ZStream |
| Target Milestone: | z6 | ||
| Target Release: | 13.0 (Queens) | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | Driver | ||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2019-03-06 16:16:19 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: | |
| Embargoed: | |||
As per depreciation notice [1], closing this bug. Please reopen if relevant for RHOSP13, as this is the only version shipping ODL. [1] https://access.redhat.com/documentation/en-us/red_hat_openstack_platform/14/html-single/release_notes/index#deprecated_functionality As per depreciation notice [1], closing this bug. Please reopen if relevant for RHOSP13, as this is the only version shipping ODL. [1] https://access.redhat.com/documentation/en-us/red_hat_openstack_platform/14/html-single/release_notes/index#deprecated_functionality |
Description of problem: neutron/server.log shows many times the following networking_odl ERROR while it is actually a warning. Please change this ERROR to WARN: ERROR networking_odl.journal.periodic_task Failed during periodic task operation journal_recovery.: InvalidRequestError: Object '<OpenDaylightJournal at 0x7fadd4d3b450>' is already attached to session Version-Release number of selected component (if applicable): 14 -p 2018-12-20.4 How reproducible: Always Steps to Reproduce: 1. Install OSP + ODL 2. Check neutron/server.log for ERRORs Actual results: *** controller-1: /var/log/containers/neutron/server.log *** 2018-12-24 10:02:09.871 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Finished full_sync phase of maintenance task. 2018-12-24 10:02:09.872 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Starting journal_recovery phase of periodic task maintenance. 2018-12-24 10:02:09.894 38 DEBUG networking_odl.journal.recovery [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Attempting recovery of journal entry <networking_odl.db.models.OpenDaylightJournal[object at 7fadd4d86050] {seqnum=32, object_type=u'network', object_uuid=u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', operation=u'update', data={'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 4, 'port_security_enabled': True, 'mtu': 1500, 'id': u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', 'router:external': True, 'availability_zone_hints': [], 'availability_zones': [u'nova'], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'70b82a4868bd42ccb36261613ac4d178', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2018-12-23T12:46:02Z', 'is_default': False, 'provider:segmentation_id': None, 'name': u'public', 'admin_state_up': True, 'tenant_id': u'70b82a4868bd42ccb36261613ac4d178', 'created_at': '2018-12-23T12:40:48Z', 'provider:network_type': None, 'vlan_transparent': None}, state='failed', retry_count=5, last_retried=datetime.datetime(2018, 12, 23, 12, 46, 3), version_id=13}>. journal_recovery /usr/lib/python2.7/site-packages/networking_odl/journal/recovery.py:39 2018-12-24 10:02:09.895 38 DEBUG networking_odl.common.client [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Sending METHOD (get) URL (http://172.17.1.28:8081/controller/nb/v2/neutron/networks/e845bd10-e12c-486a-bf0e-4f4fa3ca1234) JSON (None) request /usr/lib/python2.7/site-packages/networking_odl/common/client.py:89 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task ectxt.value = e.inner_exc 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/networking_odl/journal/periodic_task.py", line 65, in _execute_op 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 136, in wrapped 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 140, in wrapped 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 233, in wrapped 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 142, in wrapper 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 154, in wrapper 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task operation(context) 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Failed during periodic task operation journal_recovery.: InvalidRequestError: Object '<OpenDaylightJournal at 0x7fadd4d86050>' is already attached to session '17481' (this is '17490') 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task return f(*args, **kwargs) 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task return method(*args, **kwargs) 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task self.force_reraise() 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task setattr(e, '_RETRY_EXCEEDED', True) 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task six.reraise(self.type_, self.value, self.tb) 2018-12-24 10:02:09.930 38 ERROR networking_odl.journal.periodic_task Traceback (most recent call last): 2018-12-24 10:07:09.886 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Finished full_sync phase of maintenance task. 2018-12-24 10:07:09.887 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Starting journal_recovery phase of periodic task maintenance. 2018-12-24 10:07:09.905 38 DEBUG networking_odl.journal.recovery [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Attempting recovery of journal entry <networking_odl.db.models.OpenDaylightJournal[object at 7fadd4ab8450] {seqnum=32, object_type=u'network', object_uuid=u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', operation=u'update', data={'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 4, 'port_security_enabled': True, 'mtu': 1500, 'id': u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', 'router:external': True, 'availability_zone_hints': [], 'availability_zones': [u'nova'], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'70b82a4868bd42ccb36261613ac4d178', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2018-12-23T12:46:02Z', 'is_default': False, 'provider:segmentation_id': None, 'name': u'public', 'admin_state_up': True, 'tenant_id': u'70b82a4868bd42ccb36261613ac4d178', 'created_at': '2018-12-23T12:40:48Z', 'provider:network_type': None, 'vlan_transparent': None}, state='failed', retry_count=5, last_retried=datetime.datetime(2018, 12, 23, 12, 46, 3), version_id=13}>. journal_recovery /usr/lib/python2.7/site-packages/networking_odl/journal/recovery.py:39 2018-12-24 10:07:09.906 38 DEBUG networking_odl.common.client [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Sending METHOD (get) URL (http://172.17.1.28:8081/controller/nb/v2/neutron/networks/e845bd10-e12c-486a-bf0e-4f4fa3ca1234) JSON (None) request /usr/lib/python2.7/site-packages/networking_odl/common/client.py:89 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task ectxt.value = e.inner_exc 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/networking_odl/journal/periodic_task.py", line 65, in _execute_op 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 136, in wrapped 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 140, in wrapped 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 233, in wrapped 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 142, in wrapper 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 154, in wrapper 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task operation(context) 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Failed during periodic task operation journal_recovery.: InvalidRequestError: Object '<OpenDaylightJournal at 0x7fadd4ab8450>' is already attached to session '17552' (this is '17561') 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task return f(*args, **kwargs) 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task return method(*args, **kwargs) 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task self.force_reraise() 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task setattr(e, '_RETRY_EXCEEDED', True) 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task six.reraise(self.type_, self.value, self.tb) 2018-12-24 10:07:09.938 38 ERROR networking_odl.journal.periodic_task Traceback (most recent call last): 2018-12-24 10:12:09.891 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Finished full_sync phase of maintenance task. 2018-12-24 10:12:09.892 38 INFO networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Starting journal_recovery phase of periodic task maintenance. 2018-12-24 10:12:09.905 38 DEBUG networking_odl.journal.recovery [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Attempting recovery of journal entry <networking_odl.db.models.OpenDaylightJournal[object at 7fadd4d3b450] {seqnum=32, object_type=u'network', object_uuid=u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', operation=u'update', data={'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 4, 'port_security_enabled': True, 'mtu': 1500, 'id': u'e845bd10-e12c-486a-bf0e-4f4fa3ca1234', 'router:external': True, 'availability_zone_hints': [], 'availability_zones': [u'nova'], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'70b82a4868bd42ccb36261613ac4d178', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2018-12-23T12:46:02Z', 'is_default': False, 'provider:segmentation_id': None, 'name': u'public', 'admin_state_up': True, 'tenant_id': u'70b82a4868bd42ccb36261613ac4d178', 'created_at': '2018-12-23T12:40:48Z', 'provider:network_type': None, 'vlan_transparent': None}, state='failed', retry_count=5, last_retried=datetime.datetime(2018, 12, 23, 12, 46, 3), version_id=13}>. journal_recovery /usr/lib/python2.7/site-packages/networking_odl/journal/recovery.py:39 2018-12-24 10:12:09.906 38 DEBUG networking_odl.common.client [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Sending METHOD (get) URL (http://172.17.1.28:8081/controller/nb/v2/neutron/networks/e845bd10-e12c-486a-bf0e-4f4fa3ca1234) JSON (None) request /usr/lib/python2.7/site-packages/networking_odl/common/client.py:89 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task ectxt.value = e.inner_exc 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/networking_odl/journal/periodic_task.py", line 65, in _execute_op 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 136, in wrapped 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 140, in wrapped 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 233, in wrapped 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 142, in wrapper 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 154, in wrapper 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task operation(context) 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task [req-682c5a23-6441-41e4-bf5d-0df3af33b87c - - - - -] Failed during periodic task operation journal_recovery.: InvalidRequestError: Object '<OpenDaylightJournal at 0x7fadd4d3b450>' is already attached to session '17623' (this is '17632') 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task return f(*args, **kwargs) 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task return method(*args, **kwargs) 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task self.force_reraise() 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task setattr(e, '_RETRY_EXCEEDED', True) 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task six.reraise(self.type_, self.value, self.tb) 2018-12-24 10:12:09.935 38 ERROR networking_odl.journal.periodic_task Traceback (most recent call last): Expected results: If it's not a real ERROR, use WARN instead. Additional info: