Bug 1686817 - [osp15] nova is broken on the undercloud with ssl
Summary: [osp15] nova is broken on the undercloud with ssl
Keywords:
Status: CLOSED DUPLICATE of bug 1670996
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-nova
Version: 15.0 (Stein)
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: ---
: ---
Assignee: Matthew Booth
QA Contact: OSP DFG:Compute
URL:
Whiteboard:
: 1691049 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-03-08 11:56 UTC by Michele Baldessari
Modified: 2023-03-21 19:12 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-03-28 10:52:23 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
OpenStack gerrit 626952 0 None MERGED Eventlet monkey patching should be as early as possible 2020-12-07 08:31:46 UTC
OpenStack gerrit 647310 0 None MERGED Eventlet monkey patching should be as early as possible 2020-12-07 08:32:13 UTC

Description Michele Baldessari 2019-03-08 11:56:57 UTC
Description of problem:
2019-03-08 06:53:44.329 1 ERROR nova.virt.ironic.driver [req-ff716f6f-ebfe-404e-ae3a-ac1bc2ab4807 - - - - -] An unknown error has occurred when trying to get the list of nodes from the Ironic inventory. Error: maximum recursion depth exceeded: RecursionError: maximum recur
ion depth exceeded                                                                                                                                                                                                                                                               
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task [req-ff716f6f-ebfe-404e-ae3a-ac1bc2ab4807 - - - - -] Error during ComputeManager._cleanup_running_deleted_instances: nova.exception.VirtDriverNotReady: Virt driver is not ready.                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task Traceback (most recent call last):                                                                                                                                                                                    
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/virt/ironic/driver.py", line 617, in _get_node_list                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     node_list = self.ironicclient.call("node.list", **kwargs)                                                                                                                                                         
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/virt/ironic/client_wrapper.py", line 170, in call                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     return self._multi_getattr(client, method)(*args, **kwargs)                                                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/v1/node.py", line 160, in list                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     os_ironic_api_version=os_ironic_api_version)                                                                                                                                                                      
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/base.py", line 162, in _list_pagination                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp, body = self.api.json_request('GET', url, **kwargs)                                                                                                                                                          
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 678, in json_request                                                                                                                      
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp = self._http_request(url, method, **kwargs)                                                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 287, in wrapper                                                                                                                           
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     return func(self, url, method, **kwargs)                                                                                                                                                                          
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 631, in _http_request                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     self.negotiate_version(self.session, None)                                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 145, in negotiate_version                                                                                                                 
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp = _query_server(conn)                                                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 117, in _query_server                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     return self._make_simple_request(conn, 'GET', base_version)                                                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/ironicclient/common/http.py", line 623, in _make_simple_request                                                                                                              
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     endpoint_filter=endpoint_filter)                                                                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/keystoneauth1/session.py", line 814, in request                                                                                                                              
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp = send(**kwargs)                                                                                                                                                                                             
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/keystoneauth1/session.py", line 903, in _send_request                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp = self.session.request(method, url, **kwargs)                                                                                                                                                                
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/requests/sessions.py", line 524, in request                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     resp = self.send(prep, **send_kwargs)                                                                                                                                                                             
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/requests/sessions.py", line 637, in send                                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     r = adapter.send(request, **kwargs)                                                                                                                                                                               
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/requests/adapters.py", line 449, in send                                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     timeout=timeout                                                                                                                                                                                                   
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 600, in urlopen                                                                                                                             
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     chunked=chunked)                                                                                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 343, in _make_request                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     self._validate_conn(conn)                                                                                                                                                                                         
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 849, in _validate_conn                                                                                                                      
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     conn.connect()                                                                                                                                                                                                    
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/urllib3/connection.py", line 344, in connect                                                                                                                                 
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     cert_reqs=resolve_cert_reqs(self.cert_reqs),                                                                                                                                                                      
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/urllib3/util/ssl_.py", line 292, in create_urllib3_context                                                                                                                   
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     context.options |= options                                                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib64/python3.6/ssl.py", line 423, in options                                                                                                                                                            
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     super(SSLContext, SSLContext).options.__set__(self, value)                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib64/python3.6/ssl.py", line 423, in options                                                                                                                                                            
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     super(SSLContext, SSLContext).options.__set__(self, value)                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib64/python3.6/ssl.py", line 423, in options                                                                                                                                                            
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     super(SSLContext, SSLContext).options.__set__(self, value)                                                                                                                                                        
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   [Previous line repeated 297 more times]                                                                                                                                                                             
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task RecursionError: maximum recursion depth exceeded                                                                                                                                                                      
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task                                                                                                                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task During handling of the above exception, another exception occurred:                                                                                                                                                   
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task                                                                                                                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task Traceback (most recent call last):                                                                                                                                                                                    
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/oslo_service/periodic_task.py", line 222, in run_periodic_tasks                                                                                                              
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     task(self, context)                                                                                                                                                                                               
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 8073, in _cleanup_running_deleted_instances                                                                                                   
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     for instance in self._running_deleted_instances(context):                                                                                                                                                         
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 8127, in _running_deleted_instances                                                                                                           
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     instances = self._get_instances_on_driver(context, filters)                                                                                                                                                       
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 598, in _get_instances_on_driver                                                                                                              
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     driver_uuids = self.driver.list_instance_uuids()                                                                                                                                                                  
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/virt/ironic/driver.py", line 654, in list_instance_uuids                                                                                                                
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     fields=['instance_uuid'], limit=0)                                                                                                                                                                                
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task   File "/usr/lib/python3.6/site-packages/nova/virt/ironic/driver.py", line 625, in _get_node_list                                                                                                                     
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task     raise exception.VirtDriverNotReady()                                                                                                                                                                              
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task nova.exception.VirtDriverNotReady: Virt driver is not ready.                                                                                                                                                          
2019-03-08 06:53:44.329 1 ERROR oslo_service.periodic_task                                                                                                                                                                                                                       
2019-03-08 06:54:10.337 1 ERROR nova.compute.manager [req-ff716f6f-ebfe-404e-ae3a-ac1bc2ab4807 - - - - -] No compute node record for host undercloud-0.localdomain: nova.exception_Remote.ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.  
2019-03-08 06:54:10.357 1 ERROR nova.virt.ironic.driver [req-ff716f6f-ebfe-404e-ae3a-ac1bc2ab4807 - - - - -] An unknown error has occurred when trying to get the list of nodes from the Ironic inventory. Error: maximum recursion depth exceeded while calling a Python object:
RecursionError: maximum recursion depth exceeded while calling a Python object                                                                                                                                                                                                   

 [root@undercloud-0 nova]# podman ps |grep nova                                                                                                                                                        
8fd7d8f25fe2  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-compute-ironic:latest        kolla_start           31 minutes ago  Up 31 minutes ago         nova_compute    
0dcf590db45e  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-api:latest                   kolla_start           32 minutes ago  Up 32 minutes ago         nova_metadata   
db806499157d  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-api:latest                   kolla_start           32 minutes ago  Up 32 minutes ago         nova_api        
95ffc9167665  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-placement-api:latest         kolla_start           32 minutes ago  Up 32 minutes ago         nova_placement  
76246484cf79  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-scheduler:latest             kolla_start           32 minutes ago  Up 32 minutes ago         nova_scheduler  
21f22efb4711  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-conductor:latest             kolla_start           32 minutes ago  Up 32 minutes ago         nova_conductor  
f5757876077f  brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhosp15/openstack-nova-api:latest                   kolla_start           32 minutes ago  Up 32 minutes ago         nova_api_cron   
 [root@undercloud-0 nova]# podman exec -it nova_api sh -c 'rpm -qa |grep nova'                                                                                                                         
python3-novaclient-12.0.0-0.20190215094716.8eb7d1c.el8ost.noarch                                                                                                                                       
python3-nova-18.1.0-0.20190306160336.dfaa513.el8ost.noarch                                                                                                                                             
openstack-nova-api-18.1.0-0.20190306160336.dfaa513.el8ost.noarch                                                                                                                                       
openstack-nova-common-18.1.0-0.20190306160336.dfaa513.el8ost.noarch                                                                                                                                    
python3-novajoin-1.1.1-0.20190212130332.74fd4c4.el8ost.noarch                                                                                                                                          
puppet-nova-14.2.1-0.20190228120329.6d762a2.el8ost.noarch                                                                                                                                              

This is the downstream version of:
 https://bugs.launchpad.net/nova/+bug/1808975 and https://bugs.launchpad.net/nova/+bug/1808951

Comment 1 Matthew Booth 2019-03-14 15:30:00 UTC
I spent some time trying to reproduce this when it was first reported and could not. Please can you provide access to a reproducer system?

Comment 3 Matthew Booth 2019-03-14 16:51:27 UTC
Here's a trivial reproducer:

===
#!/usr/bin/python3

import eventlet
import sys
from ironicclient import client

eventlet.monkey_patch()

token=sys.argv[1]
endpoint=sys.argv[2]

ironic = client.get_client(1, os_auth_token=token, ironic_url=endpoint)
ironic.node.list()
===

Usage: ironic-list <token> <ironic https endpoint>

This raises the recursion error on the reproducer system.

Comment 4 Matthew Booth 2019-03-14 16:55:25 UTC
By moving monkey patching before importing ironicclient the issue is no longer reproduced:

===
#!/usr/bin/python3

import eventlet
eventlet.monkey_patch()

import sys
from ironicclient import client

token=sys.argv[1]
endpoint=sys.argv[2]

ironic = client.get_client(1, os_auth_token=token, ironic_url=endpoint)
ironic.node.list()
===

This is in line with my expectations documented in https://review.openstack.org/#/c/626952/.

Comment 5 Matthew Booth 2019-03-14 17:01:06 UTC
python3-eventlet-0.24.1-4.el8ost.noarch
python36-3.6.8-1.module+el8+2710+846623d6.x86_64
python3-urllib3-1.23-5.el8ost.noarch

Comment 6 Matthew Booth 2019-03-14 17:22:30 UTC
I just manually applied https://review.openstack.org/#/c/626952/ to the nova compute container and there are no longer any recursion errors.

Comment 7 Matthew Booth 2019-03-15 11:41:32 UTC
The problem is with urllib3, not ssl. The above 'fixed' version can be minimally made to reproduce again by importing 'urllib3' before eventlet.monkey_patch():

===
#!/usr/bin/python3

import urllib3
import eventlet
eventlet.monkey_patch()

import sys

from ironicclient import client

token=sys.argv[1]
endpoint=sys.argv[2]

ironic = client.get_client(1, os_auth_token=token, ironic_url=endpoint)
ironic.node.list()
===

Comment 8 Matthew Booth 2019-03-15 11:43:00 UTC
(In reply to Matthew Booth from comment #7)
> The problem is with urllib3, not ssl. The above 'fixed' version can be
> minimally made to reproduce again by importing 'urllib3' before
> eventlet.monkey_patch():

N.B.: This is not the case if you import ssl instead.

Comment 10 Matthew Booth 2019-03-15 17:49:21 UTC
I've posted a longer discussion of this bug here: http://lists.openstack.org/pipermail/openstack-discuss/2019-March/003870.html

Comment 12 Michele Baldessari 2019-03-22 14:19:44 UTC
*** Bug 1691049 has been marked as a duplicate of this bug. ***

Comment 15 Matthew Booth 2019-03-28 10:52:23 UTC

*** This bug has been marked as a duplicate of bug 1670996 ***


Note You need to log in before you can comment on or make changes to this bug.