Horizon can’t initiate connection to VNC Console while in Dashboard’s windowed mode

Bug #1614001 reported by Stanislav Kolenkin
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Mirantis OpenStack
Incomplete
Undecided
Stanislav Kolenkin

Bug Description

MOS 9.0
Steps:
1. Start instance and open its details on Console tab
2. [Bug] Note that there is an error connecting to console
3. Push button to open “Only Console” mode
4. Console connected.

Expected: Console connected either way
Actual: Windowed console can’t connect, Full screen console do connects successfully

In my opinion the error associated with the token:
handler exception: The token 'b0b2a402-b736-4a92-8f20-f205383ec463' is invalid or has expired

From nova log file /var/log/nova/nova-novncproxy.log:
2016-08-17 08:10:27.305 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:30.072 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:30.119 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:30.446 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:30.474 20047 DEBUG oslo.messaging._drivers.pool [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Pool creating new connection create /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/pool.py:109
2016-08-17 08:10:30.479 20047 DEBUG oslo.messaging._drivers.impl_rabbit [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Connecting to AMQP server on 192.168.0.3:5673 __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:539
2016-08-17 08:10:30.499 20047 DEBUG oslo.messaging._drivers.impl_rabbit [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Connected to AMQP server on 192.168.0.3:5673 via [amqp] client __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:566
2016-08-17 08:10:30.533 20047 DEBUG oslo.messaging._drivers.pool [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Pool creating new connection create /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/pool.py:109
2016-08-17 08:10:30.541 20047 DEBUG oslo.messaging._drivers.impl_rabbit [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Connecting to AMQP server on 192.168.0.3:5673 __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:539
2016-08-17 08:10:30.564 20047 DEBUG oslo.messaging._drivers.impl_rabbit [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] Connected to AMQP server on 192.168.0.3:5673 via [amqp] client __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:566
2016-08-17 08:10:30.566 20047 DEBUG oslo_messaging._drivers.amqpdriver [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] CALL msg_id: d19783b2b4b74b53a34eb70e5c0e173c size: 999 exchange: nova topic: consoleauth _send /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:496
2016-08-17 08:10:30.601 20047 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: d19783b2b4b74b53a34eb70e5c0e173c size: 146 __call__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:339
2016-08-17 08:10:30.604 20047 INFO nova.console.websocketproxy [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] handler exception: The token 'b0b2a402-b736-4a92-8f20-f205383ec463' is invalid or has expired
2016-08-17 08:10:30.605 20047 DEBUG nova.console.websocketproxy [req-e761fdbf-fc72-4156-b079-5881cb954c49 - - - - -] exception vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy Traceback (most recent call last):
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 878, in top_new_client
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy client = self.do_handshake(startsock, address)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 813, in do_handshake
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy self.RequestHandlerClass(retsock, address, self)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/nova/console/websocketproxy.py", line 171, in __init__
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy websockify.ProxyRequestHandler.__init__(self, *args, **kwargs)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 112, in __init__
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy SimpleHTTPRequestHandler.__init__(self, req, addr, server)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/SocketServer.py", line 649, in __init__
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy self.handle()
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 540, in handle
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy SimpleHTTPRequestHandler.handle(self)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/BaseHTTPServer.py", line 340, in handle
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy self.handle_one_request()
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/BaseHTTPServer.py", line 328, in handle_one_request
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy method()
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 506, in do_GET
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy if not self.handle_websocket():
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/websockify/websocket.py", line 494, in handle_websocket
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy self.new_websocket_client()
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy File "/usr/lib/python2.7/dist-packages/nova/console/websocketproxy.py", line 107, in new_websocket_client
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy raise exception.InvalidToken(token=token)
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy InvalidToken: The token 'b0b2a402-b736-4a92-8f20-f205383ec463' is invalid or has expired
2016-08-17 08:10:30.605 20047 ERROR nova.console.websocketproxy
2016-08-17 08:10:30.631 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.514 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.543 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.601 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.650 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.658 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.680 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.796 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.818 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.832 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 1 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.841 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.856 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.865 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.876 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.884 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.886 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.889 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.899 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 1 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.899 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 2 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.906 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.912 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.934 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.955 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.969 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.977 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 1 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.986 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:32.990 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:33.007 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:33.226 1016 DEBUG nova.console.websocketproxy [-] 192.168.0.8: new handler Process vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828
2016-08-17 08:10:33.247 20129 DEBUG oslo.messaging._drivers.pool [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Pool creating new connection create /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/pool.py:109
2016-08-17 08:10:33.255 20129 DEBUG oslo.messaging._drivers.impl_rabbit [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Connecting to AMQP server on 192.168.0.9:5673 __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:539
2016-08-17 08:10:33.268 20129 DEBUG oslo.messaging._drivers.impl_rabbit [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Connected to AMQP server on 192.168.0.9:5673 via [amqp] client __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:566
2016-08-17 08:10:33.283 20129 DEBUG oslo.messaging._drivers.pool [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Pool creating new connection create /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/pool.py:109
2016-08-17 08:10:33.285 20129 DEBUG oslo.messaging._drivers.impl_rabbit [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Connecting to AMQP server on 192.168.0.8:5673 __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:539
2016-08-17 08:10:33.299 20129 DEBUG oslo.messaging._drivers.impl_rabbit [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] Connected to AMQP server on 192.168.0.8:5673 via [amqp] client __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:566
2016-08-17 08:10:33.300 20129 DEBUG oslo_messaging._drivers.amqpdriver [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] CALL msg_id: db4886c598e346de8165715fe04edee9 size: 999 exchange: nova topic: consoleauth _send /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:496
2016-08-17 08:10:33.392 20129 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: db4886c598e346de8165715fe04edee9 size: 482 __call__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:339
2016-08-17 08:10:33.398 20129 INFO nova.console.websocketproxy [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] 99: connect info: {u'instance_uuid': u'1b0fa45b-96f9-461d-8689-c1d498ad5ee7', u'internal_access_path': None, u'last_activity_at': 1471421426.443397, u'console_type': u'novnc', u'host': u'192.168.0.10', u'token': u'b0b2a402-b736-4a92-8f20-f205383ec463', u'access_url': u'http://172.16.164.67:6080/vnc_auto.html?token=b0b2a402-b736-4a92-8f20-f205383ec463', u'port': u'5901'}
2016-08-17 08:10:33.399 20129 INFO nova.console.websocketproxy [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] 99: connecting to: 192.168.0.10:5901
2016-08-17 08:10:35.753 20129 DEBUG nova.console.websocketproxy [req-8de223ac-0d3d-4a84-b7ee-2e9fdb461a3e - - - - -] 99: 192.168.0.10:5901: Target closed vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:278
2016-08-17 08:10:35.782 1016 DEBUG nova.console.websocketproxy [-] Reaing zombies, active child count is 0 vmsg /usr/lib/python2.7/dist-packages/websockify/websocket.py:828

dpkg -l | grep '^ii' | grep nova
ii nova-api 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - compute API frontend
ii nova-cert 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - certificate manager
ii nova-common 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - common files
ii nova-conductor 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - conductor service
ii nova-consoleauth 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - Console Authenticator
ii nova-consoleproxy 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - NoVNC proxy
ii nova-scheduler 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - virtual machine scheduler
ii python-nova 2:13.0.0-6~u14.04+mos43 all OpenStack Compute - libraries
ii python-novaclient 2:3.3.1-4~u14.04+mos1 all client library for OpenStack Compute API - Python 2.7

Tags: area-nova
Ivan Kolodyazhny (e0ne)
affects: nova → mos
Changed in mos:
status: New → Confirmed
Revision history for this message
Denis Meltsaykin (dmeltsaykin) wrote :

Stanislav, could you please provide a diagnostic snapshot or an environment where the problem appears?

Changed in mos:
assignee: nobody → Stanislav Kolenkin (skolenkin)
status: Confirmed → Incomplete
tags: added: area-nova
Revision history for this message
Oleksandr Savatieiev (osavatieiev) wrote :

With all due respect to you Denis, this is a High priority.
And here is an effect on workload: "Client can't get to his workload/instance through Horizon."

Not just every user out there will even try to push full screen button once he/she gets error connecting message.

Diagnostic snapshot not available as the environment was re-deployed.

Revision history for this message
Matthew Roark (mroark) wrote :

If this was an HA environment, it's possible that this issue is a duplicate of: https://bugs.launchpad.net/mos/+bug/1576218

Revision history for this message
Ivan Kolodyazhny (e0ne) wrote :

It was HA env, ISO #495.

Revision history for this message
Roman Podoliaka (rpodolyaka) wrote :

Agreed with #3

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.