nova-next job fails as novnc service fails with TypeError: _wrap_socket() argument 1 must be _socket.socket, not GreenSSLSocket

[Balazs Gibizer]

Since 18th of July nova-next job fails [1] with the following stack trace in the n-novnc-cell1 service[2]:

Jul 20 10:44:42.419916 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: DEBUG nova.console.rfb.authvencrypt [None req-4c318998-3a74-4929-beab-b774a72844cf None None] Server accepted the requested sub-auth type {{(pid=23498) security_handshake /opt/stack/nova/nova/console/rfb/authvencrypt.py:126}}

Jul 20 10:44:42.425350 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: INFO nova.console.websocketproxy [None req-4c318998-3a74-4929-beab-b774a72844cf None None] handler exception: _wrap_socket() argument 1 must be _socket.socket, not GreenSSLSocket

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: DEBUG nova.console.websocketproxy [None req-4c318998-3a74-4929-beab-b774a72844cf None None] exception {{(pid=23498) vmsg /usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py:634}}

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy Traceback (most recent call last):

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 691, in top_new_client

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy client = self.do_handshake(startsock, address)

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 619, in do_handshake

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.RequestHandlerClass(retsock, address, self)

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/opt/stack/nova/nova/console/websocketproxy.py", line 100, in __init__

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy websockify.ProxyRequestHandler.__init__(self, *args, **kwargs)

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 99, in __init__

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy SimpleHTTPRequestHandler.__init__(self, req, addr, server)

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/lib/python3.6/socketserver.py", line 724, in __init__

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.handle()

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 315, in handle

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy SimpleHTTPRequestHandler.handle(self)

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/lib/python3.6/http/server.py", line 418, in handle

Jul 20 10:44:42.435706 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.handle_one_request()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websocketserver.py", line 47, in handle_one_request

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy super(WebSocketRequestHandlerMixIn, self).handle_one_request()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/lib/python3.6/http/server.py", line 406, in handle_one_request

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy method()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websocketserver.py", line 60, in _websocket_do_GET

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.handle_upgrade()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 221, in handle_upgrade

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy WebSocketRequestHandlerMixIn.handle_upgrade(self)

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websocketserver.py", line 87, in handle_upgrade

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.handle_websocket()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/websockify/websockifyserver.py", line 259, in handle_websocket

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy self.new_websocket_client()

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/opt/stack/nova/nova/console/websocketproxy.py", line 265, in new_websocket_client

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy tsock = self.server.security_proxy.connect(tenant_sock, tsock)

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/opt/stack/nova/nova/console/securityproxy/rfb.py", line 181, in connect

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy compute_sock = scheme.security_handshake(compute_sock)

Jul 20 10:44:42.437262 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/opt/stack/nova/nova/console/rfb/authvencrypt.py", line 143, in security_handshake

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy ca_certs=CONF.vnc.vencrypt_ca_certs)

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/eventlet/green/ssl.py", line 414, in wrap_socket

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy return GreenSSLSocket(sock, *a, **kw)

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/local/lib/python3.6/dist-packages/eventlet/green/ssl.py", line 106, in __init__

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy ca_certs, do_handshake_on_connect and six.PY2, *args, **kw)

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy File "/usr/lib/python3.6/ssl.py", line 809, in __init__

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy server_hostname)

Jul 20 10:44:42.439249 ubuntu-bionic-rax-ord-0018472470 nova-novncproxy[22231]: ERROR nova.console.websocketproxy TypeError: _wrap_socket() argument 1 must be _socket.socket, not GreenSSLSocket

Sean Mooney opened an upstream bug report in eventlet [3].

The last passing job run [4] and the failing run[2] have the same eventlet, websockify, openssl and libssl-dev versions.

[1] https://zuul.opendev.org/t/openstack/builds?job_name=nova-next&project=openstack%2Fnova&branch=master

[2] https://zuul.opendev.org/t/openstack/build/1180d2313ade4d5480550313bcd20b79/log/controller/logs/screen-n-novnc-cell1.txt#29

[3] https://github.com/eventlet/eventlet/issues/632

[4] https://zuul.opendev.org/t/openstack/build/1d23dbdf6fa84702ab543602cae1ba67/log/job-output.txt

[melanie witt (melwitt)]

Just a FYI, the reason this fails only in the nova-next job is because in nova-next we test the SSL/TLS configuration of the novnc console proxy and the error is being raised in the vencrypt-related code:

https://github.com/openstack/nova/blob/b7161fe9b92f0045e97c300a80e58d32b6f49be1/nova/console/rfb/authvencrypt.py#L137

[Balazs Gibizer (balazs-gibizer)]

With the following local.conf addition I was able to reproduce the problem in a local devstack based on ubuntu 18.04

USE_SSL=True
ENABLED_SERVICES+=,tls-proxy
GLANCE_STANDALONE=False
NOVA_CONSOLE_PROXY_COMPUTE_TLS=True

[Balazs Gibizer (balazs-gibizer)]

This could be a relevant warning

"Modules with known eventlet monkey patching issues were imported prior to eventlet monkey patching: urllib3. This warning can usually be ignored if the caller is only importing and not executing nova code."[1]

As it is not visible in the passing job but visible in the failing one.

[1] https://zuul.opendev.org/t/openstack/build/1180d2313ade4d5480550313bcd20b79/log/controller/logs/screen-n-novnc-cell1.txt#3

[Balazs Gibizer (balazs-gibizer)]

This is the module import order when the fault happens

http://paste.openstack.org/show/796133/

[Balazs Gibizer (balazs-gibizer)]

https://review.opendev.org/#/c/741800/ bumped dnspython from 1.16.0 to 2.0.0 that causing eventlet to imports the dns package and that import requests which imports urllib3 causing the issue. Pulling dnspython package back to 1.16.0 locally solves the issue.

[Balazs Gibizer (balazs-gibizer)]

The upstream eventlet issue is tracked in https://github.com/eventlet/eventlet/issues/619

[Balazs Gibizer (balazs-gibizer)]

A patch proposed to pin the requirements in OpenStack https://review.opendev.org/#/c/741986/

[Balazs Gibizer (balazs-gibizer)]

It seems that https://review.opendev.org/#/c/741986 resolve the issue. Marking this bug fixed.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.opendev.org/761427

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/requirements yoga-eom release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/requirements victoria-eom release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/requirements wallaby-eom release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/requirements xena-eom release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/requirements zed-eom release.