Bug 1309448

Summary: [Upgrade][ovirt-websocket-proxy] ovirt-websocket-proxy failed to start after upgrading a RHEV system 3.5->3.6
Product: [oVirt] ovirt-engine Reporter: Gil Klein <gklein>
Component: WebSocket ProxyAssignee: Simone Tiraboschi <stirabos>
WebSocket Proxy sub component: Packaging QA Contact: Petr Matyáš <pmatyas>
Status: CLOSED CURRENTRELEASE Docs Contact:
Severity: urgent    
Priority: unspecified CC: dfediuck, gklein, oourfali, sbonazzo, ylavi
Version: 3.6.3.2Keywords: TestOnly
Target Milestone: ovirt-3.6.3Flags: rule-engine: ovirt-3.6.z+
rule-engine: blocker+
ylavi: planning_ack+
rule-engine: devel_ack+
gklein: testing_ack+
Target Release: 3.6.3.2   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Known Issue
Doc Text:
Cause: API change in python-websockify Consequence: engine-setup fails stopping ovirt-engine-websocket if python-websockify is upgraded before executing engine-setup. This can happen only if after enabling 3.6 user perform "yum update --skip-broken". Workaround (if any): avoid to run "yum update --skip-broken" and just execute "yum update rhevm-setup\*" and then engine-setup. Result: it should work without further issue.
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-03-11 07:22:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Integration RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1285700    
Attachments:
Description Flags
ovirt engine setup log none

Description Gil Klein 2016-02-17 20:21:35 UTC
Created attachment 1128009 [details]
ovirt engine setup log

Description of problem:

ovirt-websocket-proxy failed to start after upgrading a RHEV system 3.5->3.6

[INFO  ] Starting engine service
[ INFO  ] Restarting httpd
[ INFO  ] Starting dwh service
[ INFO  ] Starting reports service
[ ERROR ] Failed to execute stage 'Closing up': Failed to start service 'ovirt-websocket-proxy'
[ INFO  ] Stage: Clean up
          Log file is located at /var/log/ovirt-engine/setup/ovirt-engine-setup-20160217205652-mdno1v.log
[ INFO  ] Generating answer file '/var/lib/ovirt-engine/setup/answers/20160217214658-setup.conf'
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination
[ ERROR ] Execution of setup failed


Version-Release number of selected component (if applicable):
Installed: rhevm-3.5.8-0.1.el6ev.noarch
Updated: rhevm-3.6.3.2-0.1.el6.noarch
Installed: rhevm-setup-plugin-websocket-proxy-3.5.8-0.1.el6ev.noarch
Installed: rhevm-websocket-proxy-3.5.8-0.1.el6ev.noarch
Updated: rhevm-setup-plugin-websocket-proxy-3.6.3.2-0.1.el6.noarch
Updated: rhevm-websocket-proxy-3.6.3.2-0.1.el6.noarch

How reproducible:
100%


Steps to Reproduce:
1. Install a 3.5 engine
2. Configure the system using engine-setup
3. Add 3.6 repos and install the rhevm-setup* pacakges
4. Configure the system using engine-setup
5. Make sure to enable 

Actual results:
Failed to start service 'ovirt-websocket-proxy'


Expected results:
ovirt-websocket-proxy should be started successfully 


Additional info:

When trying to start the service manually:

# service ovirt-websocket-proxy start
Starting oVirt Engine websockets proxy: Traceback (most recent call last):
  File "/usr/share/ovirt-engine/services/ovirt-websocket-proxy/ovirt-websocket-proxy.py", line 33, in <module>
    class OvirtProxyRequestHandler(websockify.ProxyRequestHandler):
AttributeError: 'module' object has no attribute 'ProxyRequestHandler'
                                                           [FAILED]
ovirt-engine-setup.log

2016-02-17 21:46:57 DEBUG otopi.plugins.otopi.services.rhel plugin.execute:941 execute-output: ('/sbin/service', 'ovirt-websocket-proxy', 'start') stderr:
Traceback (most recent call last):
  File "/usr/share/ovirt-engine/services/ovirt-websocket-proxy/ovirt-websocket-proxy.py", line 33, in <module>
    class OvirtProxyRequestHandler(websockify.ProxyRequestHandler):
AttributeError: 'module' object has no attribute 'ProxyRequestHandler'

2016-02-17 21:46:57 DEBUG otopi.context context._executeMethod:156 method exception
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/otopi/context.py", line 146, in _executeMethod
    method['method']()
  File "/usr/share/ovirt-engine/setup/bin/../plugins/ovirt-engine-setup/websocket_proxy/config.py", line 281, in _closeup
    state=state,
  File "/usr/share/otopi/plugins/otopi/services/rhel.py", line 213, in state
    service=name,
RuntimeError: Failed to start service 'ovirt-websocket-proxy'

Comment 1 Sandro Bonazzola 2016-02-18 14:01:55 UTC
Can you provide version of websockify package?

Comment 2 Gil Klein 2016-02-18 14:10:49 UTC
(In reply to Sandro Bonazzola from comment #1)
> Can you provide version of websockify package?

rhevm-websocket-proxy-3.6.3.2-0.1.el6.noarch
python-websockify-0.6.0-2.el6.noarch

Comment 3 Simone Tiraboschi 2016-02-18 16:53:17 UTC
Unable to reproduce upgrading from RHEVM 3.5.8 Z-STREAM vt20 to  RHEVM 3.6.3.2 WEEKLY 3.6.3-3

At the end:

rhevm-setup-plugin-websocket-proxy.noarch                                                                       3.6.3.2-0.1.el6                                                                       @rhev-3.6.3-3

rhevm-websocket-proxy.noarch                                                                                    3.6.3.2-0.1.el6                                                                       @rhev-3.6.3-3

python-websockify.noarch                                                                                 0.6.0-2.el6                                                                                  @rhev-3.6.3-3

[root@r6720160218et1 ~]# service ovirt-websocket-proxy status
ovirt-websocket-proxy (pid  29680) is running...


Executing engine-setup after the upgrade:
          --== PACKAGES ==--
         
[ INFO  ] Checking for product updates...
          Setup has found updates for some packages:
          PACKAGE: [install] ebay-cors-filter-1.0.1-1.el6.noarch
          PACKAGE: [updated] ovirt-host-deploy-1.3.2-1.el6ev.noarch
          PACKAGE: [update] ovirt-host-deploy-1.4.1-1.el6ev.noarch
          PACKAGE: [updated] ovirt-host-deploy-java-1.3.2-1.el6ev.noarch
          PACKAGE: [update] ovirt-host-deploy-java-1.4.1-1.el6ev.noarch
          PACKAGE: [install] ovirt-vmconsole-1.0.0-1.el6ev.noarch
          PACKAGE: [install] ovirt-vmconsole-proxy-1.0.0-1.el6ev.noarch
          PACKAGE: [updated] python-websockify-0.5.1-1.1.el6.noarch
          PACKAGE: [update] python-websockify-0.6.0-2.el6.noarch
          PACKAGE: [updated] rcue1-1.0.5-1.el6_5.noarch
          PACKAGE: [update] rcue1-1.3.0-1.el6.noarch
          PACKAGE: [updated] redhat-support-plugin-rhev-3.5.0-1.el6ev.noarch
          PACKAGE: [update] redhat-support-plugin-rhev-3.6.0-12.el6.noarch
          PACKAGE: [updated] rhevm-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-backend-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-backend-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-branding-rhev-3.5.0-4.el6ev.noarch
          PACKAGE: [update] rhevm-branding-rhev-3.6.0-7.el6ev.noarch
          PACKAGE: [updated] rhevm-cli-3.5.0.6-1.el6ev.noarch
          PACKAGE: [update] rhevm-cli-3.6.2.0-1.el6ev.noarch
          PACKAGE: [updated] rhevm-dbscripts-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-dbscripts-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-dependencies-3.5.1-1.el6ev.noarch
          PACKAGE: [update] rhevm-dependencies-3.6.0-1.el6ev.noarch
          PACKAGE: [updated] rhevm-doc-3.5.3-1.el6eng.noarch
          PACKAGE: [update] rhevm-doc-3.6.0-3.el6eng.noarch
          PACKAGE: [updated] rhevm-extensions-api-impl-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-extensions-api-impl-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-image-uploader-3.5.0-4.el6ev.noarch
          PACKAGE: [update] rhevm-image-uploader-3.6.0-1.el6ev.noarch
          PACKAGE: [updated] rhevm-iso-uploader-3.5.1-1.el6ev.noarch
          PACKAGE: [update] rhevm-iso-uploader-3.6.0-1.el6ev.noarch
          PACKAGE: [updated] rhevm-log-collector-3.5.4-2.el6ev.noarch
          PACKAGE: [update] rhevm-log-collector-3.6.1-1.el6ev.noarch
          PACKAGE: [updated] rhevm-restapi-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-restapi-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-sdk-python-3.5.6.0-1.el6ev.noarch
          PACKAGE: [update] rhevm-sdk-python-3.6.3.0-1.el6ev.noarch
          PACKAGE: [install] rhevm-setup-plugin-vmconsole-proxy-helper-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-spice-client-x64-cab-3.5-3.el6.noarch
          PACKAGE: [update] rhevm-spice-client-x64-cab-3.6-6.el6.noarch
          PACKAGE: [updated] rhevm-spice-client-x64-msi-3.5-3.el6.noarch
          PACKAGE: [update] rhevm-spice-client-x64-msi-3.6-6.el6.noarch
          PACKAGE: [updated] rhevm-spice-client-x86-cab-3.5-3.el6.noarch
          PACKAGE: [update] rhevm-spice-client-x86-cab-3.6-6.el6.noarch
          PACKAGE: [updated] rhevm-spice-client-x86-msi-3.5-3.el6.noarch
          PACKAGE: [update] rhevm-spice-client-x86-msi-3.6-6.el6.noarch
          PACKAGE: [updated] rhevm-tools-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-tools-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-userportal-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-userportal-3.6.3.2-0.1.el6.noarch
          PACKAGE: [install] rhevm-vmconsole-proxy-helper-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-webadmin-portal-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-webadmin-portal-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] rhevm-websocket-proxy-3.5.8-0.1.el6ev.noarch
          PACKAGE: [update] rhevm-websocket-proxy-3.6.3.2-0.1.el6.noarch
          PACKAGE: [updated] vdsm-jsonrpc-java-1.0.15-1.el6ev.noarch
          PACKAGE: [update] vdsm-jsonrpc-java-1.1.8-1.el6ev.noarch
          do you wish to update them now? (Yes, No) [Yes]: 
[ INFO  ] Checking for an update for Setup...
....
          --== END OF SUMMARY ==--
         
[ INFO  ] Starting engine service
[ INFO  ] Restarting httpd
[ INFO  ] Stage: Clean up
          Log file is located at /var/log/ovirt-engine/setup/ovirt-engine-setup-20160218171520-e3ipnb.log
[ INFO  ] Generating answer file '/var/lib/ovirt-engine/setup/answers/20160218172603-setup.conf'
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination
[ INFO  ] Execution of setup completed successfully

Comment 4 Simone Tiraboschi 2016-02-18 17:01:57 UTC
Not sure why but on Gil's log ovirt-websocket-proxy also fails to stop:

2016-02-17 21:46:53 DEBUG otopi.plugins.otopi.services.rhel plugin.executeRaw:828 execute: ('/sbin/service', 'ovirt-websocket-proxy', 'start'), executable='None', cwd='None', env=None
2016-02-17 21:46:57 DEBUG otopi.plugins.otopi.services.rhel plugin.executeRaw:878 execute-result: ('/sbin/service', 'ovirt-websocket-proxy', 'start'), rc=1
2016-02-17 21:46:57 DEBUG otopi.plugins.otopi.services.rhel plugin.execute:936 execute-output: ('/sbin/service', 'ovirt-websocket-proxy', 'start') stdout:
Starting oVirt Engine websockets proxy: [FAILED]

2016-02-17 21:46:57 DEBUG otopi.plugins.otopi.services.rhel plugin.execute:941 execute-output: ('/sbin/service', 'ovirt-websocket-proxy', 'start') stderr:
Traceback (most recent call last):
  File "/usr/share/ovirt-engine/services/ovirt-websocket-proxy/ovirt-websocket-proxy.py", line 33, in <module>
    class OvirtProxyRequestHandler(websockify.ProxyRequestHandler):
AttributeError: 'module' object has no attribute 'ProxyRequestHandler'

2016-02-17 21:46:57 DEBUG otopi.context context._executeMethod:156 method exception
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/otopi/context.py", line 146, in _executeMethod
    method['method']()
  File "/usr/share/ovirt-engine/setup/bin/../plugins/ovirt-engine-setup/websocket_proxy/config.py", line 281, in _closeup
    state=state,
  File "/usr/share/otopi/plugins/otopi/services/rhel.py", line 213, in state
    service=name,
RuntimeError: Failed to start service 'ovirt-websocket-proxy'

Comment 5 Simone Tiraboschi 2016-02-18 17:14:44 UTC
In my case I see:
          PACKAGE: [install] ovirt-vmconsole-1.0.0-1.el6ev.noarch
          PACKAGE: [install] ovirt-vmconsole-proxy-1.0.0-1.el6ev.noarch
          PACKAGE: [updated] python-websockify-0.5.1-1.1.el6.noarch
          PACKAGE: [update] python-websockify-0.6.0-2.el6.noarch
          PACKAGE: [updated] rcue1-1.0.5-1.el6_5.noarch
          PACKAGE: [update] rcue1-1.3.0-1.el6.noarch
          PACKAGE: [updated] redhat-support-plugin-rhev-3.5.0-1.el6ev.noarch
          PACKAGE: [update] redhat-support-plugin-rhev-3.6.0-12.el6.noarch

While on Gil logs:

2016-02-17 20:57:28 DEBUG otopi.plugins.ovirt_engine_setup.ovirt_engine_common.distro-rpm.packages packages.verbose:196 Yum     install    - ovirt-vmconsole-1.0.0-1.el6ev.noarch
2016-02-17 20:57:28 DEBUG otopi.plugins.ovirt_engine_setup.ovirt_engine_common.distro-rpm.packages packages.verbose:196 Yum     install    - ovirt-vmconsole-proxy-1.0.0-1.el6ev.noarch
2016-02-17 20:57:28 DEBUG otopi.plugins.ovirt_engine_setup.ovirt_engine_common.distro-rpm.packages packages.verbose:196 Yum     updated    - redhat-support-plugin-rhev-3.5.0-1.el6ev.noarch
2016-02-17 20:57:28 DEBUG otopi.plugins.ovirt_engine_setup.ovirt_engine_common.distro-rpm.packages packages.verbose:196 Yum     update     - redhat-support-plugin-rhev-3.6.0-12.el6.noarch

so python-websockify and rcue1 have been updated before running engine-setup probably running:
 yum update
While I run
 yum update rhevm-setup*

And indeed python-websockify is not under version-lock:
[root@r6720160218et1 ~]# cat /etc/yum/pluginconf.d/versionlock.list
rhevm-3.6.3.2-0.1.el6.noarch
rhevm-userportal-3.6.3.2-0.1.el6.noarch
rhevm-dbscripts-3.6.3.2-0.1.el6.noarch
redhat-support-plugin-rhev-3.6.0-12.el6.noarch
rhevm-webadmin-portal-3.6.3.2-0.1.el6.noarch
rhevm-restapi-3.6.3.2-0.1.el6.noarch
ovirt-engine-extension-aaa-jdbc-1.0.6-1.el6ev.noarch
rhevm-tools-3.6.3.2-0.1.el6.noarch
rhevm-backend-3.6.3.2-0.1.el6.noarch

So we have due possibility here:
- fix the compatibility of rhevm-websocket-proxy-3.5.8 with python-websockify-0.6.0
- put python-websockify-0.5.1 under versionlock from 
rhevm-setup-plugin-websocket-proxy-3.5.8

Comment 6 Sandro Bonazzola 2016-02-19 09:21:53 UTC
Please update documentation with known issue.

Comment 7 Simone Tiraboschi 2016-02-19 09:37:06 UTC
Simply running 'yum update' will not update the system since:

--> Processing Dependency: vdsm-jsonrpc-java < 1.1.0 for package: rhevm-backend-3.5.8-0.1.el6ev.noarch
--> Finished Dependency Resolution
Error: Package: rhevm-backend-3.5.8-0.1.el6ev.noarch (@qa-latest)
           Requires: vdsm-jsonrpc-java < 1.1.0
           Removing: vdsm-jsonrpc-java-1.0.15-1.el6ev.noarch (@qa-latest)
               vdsm-jsonrpc-java = 1.0.15-1.el6ev
           Updated By: vdsm-jsonrpc-java-1.1.8-1.el6ev.noarch (rhev-3.6.3-3)
               vdsm-jsonrpc-java = 1.1.8-1.el6ev
 You could try using --skip-broken to work around the problem
 You could try running: rpm -Va --nofiles --nodigest

The correct way is 'yum update rhevm-setup*' which doesn't download python-websockify-0.6.0

The only ways to get python-websockify-0.6.0 from 2.6 repos before installing rhevm-setup are:
yum update python-websockify-0.6.0
or
yum update --skip-broken

and none or them is advised or supported.

Comment 8 Petr Matyáš 2016-02-22 12:07:42 UTC
Verified on 3.6.3-3