Bug 1421086

Summary: SPICE connections to RHV fill up log with error message
Product: Red Hat CloudForms Management Engine Reporter: Pete Savage <psavage>
Component: UI - OPSAssignee: Dávid Halász <dhalasz>
Status: CLOSED CURRENTRELEASE QA Contact: Angelina Vasileva <anikifor>
Severity: high Docs Contact:
Priority: high    
Version: 5.7.0CC: dhalasz, hkataria, jhardy, mhradil, movciari, mpovolny, obarenbo, psavage, simaishi
Target Milestone: GAKeywords: TestOnly, ZStream
Target Release: 5.8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: ui, rhev
Fixed In Version: 5.8.0.2 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1424255 (view as bug list) Environment:
Last Closed: 2017-06-12 17:21:53 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: Bug
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: CFME Core Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1424255    

Description Pete Savage 2017-02-10 10:16:45 UTC
Description of problem: SPICE connections to RHV fill up log with error message at a rate of 1.7MB per minute


Version-Release number of selected component (if applicable): 5.7.1.1


How reproducible: 100%


Steps to Reproduce:
1. Add a RHV provider to the appliance
2. Start a "VM Console" session to a SPICE activated VM
3. Interact with the VM console

Actual results: production.log endlessly spews the error traceback below despite the machine connection working. This could fill up logs very quickly.


Expected results: No error


Additional info:

    [----] F, [2017-02-10T04:40:43.412698 #38829:d5c2e4] FATAL -- : Error caught: [ActionController::ParameterMissing] param is missing or the value is empty: secret
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/strong_parameters.rb:308:in `require'
    /var/www/miq/vmdb/app/controllers/vm_common.rb:165:in `block in launch_html5_console'
    /var/www/miq/vmdb/app/controllers/vm_common.rb:165:in `each'
    /var/www/miq/vmdb/app/controllers/vm_common.rb:165:in `launch_html5_console'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/base.rb:188:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:126:in `call'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:455:in `call'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:90:in `run_callbacks'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/callbacks.rb:19:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/rescue.rb:20:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications.rb:164:in `block in instrument'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications.rb:164:in `instrument'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
    /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/base.rb:126:in `process'
    /opt/rh/cfme-gemset/gems/actionview-5.0.0.1/lib/action_view/rendering.rb:30:in `process'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal.rb:190:in `dispatch'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal.rb:262:in `dispatch'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:32:in `serve'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:39:in `block in serve'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:26:in `each'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:26:in `serve'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:725:in `call'
    /opt/rh/cfme-gemset/gems/secure_headers-3.0.3/lib/secure_headers/middleware.rb:10:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/etag.rb:25:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/conditional_get.rb:25:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/head.rb:12:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/session/abstract/id.rb:222:in `context'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/session/abstract/id.rb:216:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/cookies.rb:613:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:90:in `run_callbacks'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
    /opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/rack/logger.rb:36:in `call_app'
    /opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/rack/logger.rb:26:in `call'
    /opt/rh/cfme-gemset/gems/request_store-1.3.2/lib/request_store/middleware.rb:9:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/request_id.rb:24:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/method_override.rb:22:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/runtime.rb:22:in `call'
    /opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
    /opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/executor.rb:12:in `call'
    /opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/sendfile.rb:111:in `call'
    /opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/engine.rb:522:in `call'
    /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/configuration.rb:224:in `call'
    /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:561:in `handle_request'
    /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:406:in `process_client'
    /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:271:in `block in run'
    /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `block in spawn_thread'
    [----] I, [2017-02-10T04:40:43.413744 #38829:d5c2e4]  INFO -- :   Rendered layouts/_exception_contents.html.haml (0.1ms)

Comment 2 Dávid Halász 2017-02-10 13:16:18 UTC
Can you see any HTTP errors in the browser's JS console? I think I know this issue...

Comment 3 Dávid Halász 2017-02-13 09:01:41 UTC
It seems like a bug in SPICE-HTML5 as I can reproduce this independently from our codebase.

Comment 6 CFME Bot 2017-02-14 08:57:38 UTC
New commit detected on ManageIQ/manageiq-ui-classic/master:
https://github.com/ManageIQ/manageiq-ui-classic/commit/8f99284ec0030ff0b4918600f88ea31e9c65e57c

commit 8f99284ec0030ff0b4918600f88ea31e9c65e57c
Author:     Martin Hradil <mhradil>
AuthorDate: Mon Feb 13 18:00:20 2017 +0000
Commit:     Martin Hradil <mhradil>
CommitDate: Mon Feb 13 18:00:20 2017 +0000

    Update spice-html5-bower to 1.6.3, fixing an extra GET .../null request
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1421086

 bower.json | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Comment 7 CFME Bot 2017-02-15 15:01:12 UTC
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/c2bdc50522e36bd216e4249caf9ce99d0f9d7dda

commit c2bdc50522e36bd216e4249caf9ce99d0f9d7dda
Author:     Martin Hradil <mhradil>
AuthorDate: Mon Feb 13 18:01:20 2017 +0000
Commit:     Martin Hradil <mhradil>
CommitDate: Mon Feb 13 18:01:20 2017 +0000

    Update spice-html5-bower to 1.6.3, fixing an extra GET .../null request
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1421086

 bower.json | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)