Description of problem: HTML5 console is broken Version-Release number of selected component (if applicable): 5.6.0.1-beta2.20160413141124_e25ac0e How reproducible: 100% Steps to Reproduce: 1. Configure appliance for HTML5 2. Try to launch html5 console on either (vnc or spice) Actual results: Throws error stating "only generation of JSON objects or arrays allowed [vm_infra/launch_tml5_console] Expected results: html5 console should get launched without any error message Additional info: production.log: ============== [----] I, [2016-04-15T09:34:47.577631 #29199:13e2c94] INFO -- : Started POST "/vm_infra/html5_console/369" for 127.0.0.1 at 2016-04-15 09:34:47 -0400 [----] I, [2016-04-15T09:34:47.579809 #29199:13e2c94] INFO -- : Processing by VmInfraController#html5_console as JS [----] I, [2016-04-15T09:34:47.579933 #29199:13e2c94] INFO -- : Parameters: {"id"=>"369"} [----] I, [2016-04-15T09:34:48.373196 #29199:13e2c94] INFO -- : Completed 200 OK in 793ms (Views: 2.3ms | ActiveRecord: 0.0ms) [----] I, [2016-04-15T09:34:52.214815 #29199:13e2514] INFO -- : Started POST "/vm_infra/wait_for_task?escape=false&task_id=31" for 127.0.0.1 at 2016-04-15 09:34:52 -0400 [----] I, [2016-04-15T09:34:52.217139 #29199:13e2514] INFO -- : Processing by VmInfraController#wait_for_task as JS [----] I, [2016-04-15T09:34:52.217281 #29199:13e2514] INFO -- : Parameters: {"authenticity_token"=>"KHTC4ebEDBMVtGI2PzhI+e2O8dVEnNdzUdwTiaLz/rCfOD8KlpdUP9Z+w7TFcq2R44AK+SPOpFPzbbcUoggVrQ==", "escape"=>"false", "task_id"=>"31"} [----] I, [2016-04-15T09:34:52.448955 #29199:13e2514] INFO -- : Completed 200 OK in 231ms (Views: 2.1ms | ActiveRecord: 0.0ms) [----] I, [2016-04-15T09:34:56.462139 #29199:13e2424] INFO -- : Started POST "/vm_infra/wait_for_task?escape=false&task_id=31" for 127.0.0.1 at 2016-04-15 09:34:56 -0400 [----] I, [2016-04-15T09:34:56.464514 #29199:13e2424] INFO -- : Processing by VmInfraController#wait_for_task as JS [----] I, [2016-04-15T09:34:56.464660 #29199:13e2424] INFO -- : Parameters: {"authenticity_token"=>"CxsVrEciPw5x+0iae3iLlxjK31X4lUEN5x9gKYaoOw+8V+hHN3FnIrIx6RiBMm7/FsQkeZ/HMi1FrsS0hlPQEg==", "escape"=>"false", "task_id"=>"31"} [----] I, [2016-04-15T09:34:56.628889 #29199:13e2424] INFO -- : Completed 200 OK in 164ms (Views: 1.9ms | ActiveRecord: 0.0ms) [----] I, [2016-04-15T09:35:00.888032 #29199:13e2b7c] INFO -- : Started POST "/vm_infra/wait_for_task?escape=false&task_id=31" for 127.0.0.1 at 2016-04-15 09:35:00 -0400 [----] I, [2016-04-15T09:35:00.890577 #29199:13e2b7c] INFO -- : Processing by VmInfraController#wait_for_task as JS [----] I, [2016-04-15T09:35:00.890738 #29199:13e2b7c] INFO -- : Parameters: {"authenticity_token"=>"qXp4g9a986xbySEMFzOHiSSlXSR0FSExCLA2mAKqKT8eNoVopu6rgJgDgI7teWLhKqumCBNHUhGqAZIFAlHCIg==", "escape"=>"false", "task_id"=>"31"} [----] I, [2016-04-15T09:35:01.339221 #29199:13e2b7c] INFO -- : Completed 200 OK in 448ms (Views: 2.4ms | ActiveRecord: 0.0ms) [----] I, [2016-04-15T09:35:01.656744 #29199:13e2d84] INFO -- : Started GET "/vm_infra/launch_html5_console/369?proto=vnc&secret=dKcYEFq9&url=ws%2Fconsole%2F12be35c07bcfc582b89b12c5db85a2b8" for 127.0.0.1 at 2016-04-15 09:35:01 -0400 [----] I, [2016-04-15T09:35:01.658960 #29199:13e2d84] INFO -- : Processing by VmInfraController#launch_html5_console as HTML [----] I, [2016-04-15T09:35:01.659133 #29199:13e2d84] INFO -- : Parameters: {"proto"=>"vnc", "secret"=>"dKcYEFq9", "url"=>"ws/console/12be35c07bcfc582b89b12c5db85a2b8", "id"=>"369"} [----] F, [2016-04-15T09:35:01.818956 #29199:13e2d84] FATAL -- : Error caught: [JSON::GeneratorError] only generation of JSON objects or arrays allowed /opt/rh/cfme-gemset/gems/json_pure-1.8.3/lib/json/common.rb:223:in `generate' /opt/rh/cfme-gemset/gems/json_pure-1.8.3/lib/json/common.rb:223:in `generate' /opt/rh/cfme-gemset/gems/json_pure-1.8.3/lib/json/common.rb:446:in `block in j' /opt/rh/cfme-gemset/gems/json_pure-1.8.3/lib/json/common.rb:445:in `each' /opt/rh/cfme-gemset/gems/json_pure-1.8.3/lib/json/common.rb:445:in `j' /var/www/miq/vmdb/app/controllers/vm_common.rb:139:in `launch_html5_console' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/abstract_controller/base.rb:181:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/rendering.rb:30:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/abstract_controller/callbacks.rb:20:in `block in process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:126:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:126:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:455:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:455:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:101:in `__run_callbacks__' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/abstract_controller/callbacks.rb:19:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/rescue.rb:31:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/notifications.rb:164:in `block in instrument' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/notifications/instrumenter.rb:21:in `instrument' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/notifications.rb:164:in `instrument' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/instrumentation.rb:30:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal/params_wrapper.rb:248:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activerecord/lib/active_record/railties/controller_runtime.rb:18:in `process_action' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/abstract_controller/base.rb:126:in `process' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionview/lib/action_view/rendering.rb:30:in `process' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal.rb:190:in `dispatch' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_controller/metal.rb:262:in `dispatch' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/routing/route_set.rb:50:in `dispatch' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/routing/route_set.rb:32:in `serve' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/journey/router.rb:39:in `block in serve' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/journey/router.rb:26:in `each' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/journey/router.rb:26:in `serve' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/routing/route_set.rb:739:in `call' /opt/rh/cfme-gemset/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!' /opt/rh/cfme-gemset/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call' /opt/rh/cfme-gemset/gems/omniauth-1.3.1/lib/omniauth/builder.rb:63: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.0.alpha/lib/rack/etag.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/conditional_get.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/head.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/session/abstract/id.rb:220:in `context' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/session/abstract/id.rb:214:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/cookies.rb:613:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:97:in `__run_callbacks__' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:750:in `_run_call_callbacks' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/callbacks.rb:36:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/remote_ip.rb:79:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/railties/lib/rails/rack/logger.rb:36:in `call_app' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/railties/lib/rails/rack/logger.rb:26:in `call' /opt/rh/cfme-gemset/gems/request_store-1.3.1/lib/request_store/middleware.rb:9:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/request_id.rb:24:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/method_override.rb:22:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/runtime.rb:22:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/activesupport/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/actionpack/lib/action_dispatch/middleware/executor.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.0.alpha/lib/rack/sendfile.rb:111:in `call' /opt/rh/cfme-gemset/bundler/gems/rails-efaa6e4f79d4/railties/lib/rails/engine.rb:522:in `call' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/configuration.rb:224:in `call' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:561:in `handle_request' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:406:in `process_client' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:271:in `block in run' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `call' /opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `block in spawn_thread' [----] I, [2016-04-15T09:35:01.820977 #29199:13e2d84] INFO -- : Rendering layouts/exception.html.haml within layouts/application [----] I, [2016-04-15T09:35:01.849761 #29199:13e2d84] INFO -- : Rendered layouts/_exception_contents.html.haml (0.3ms) [----] I, [2016-04-15T09:35:01.850070 #29199:13e2d84] INFO -- : Rendered layouts/exception.html.haml within layouts/application (28.8ms) [----] I, [2016-04-15T09:35:01.850595 #29199:13e2d84] INFO -- : Rendered layouts/_doctype.html.haml (0.1ms) [----] I, [2016-04-15T09:35:01.852849 #29199:13e2d84] INFO -- : Rendered stylesheets/_template50.html.haml (0.2ms) [----] I, [2016-04-15T09:35:01.855914 #29199:13e2d84] INFO -- : Rendered layouts/_i18n_js.html.haml (2.0ms) [----] I, [2016-04-15T09:35:01.862004 #29199:13e2d84] INFO -- : Rendered layouts/_user_options.html.haml (5.1ms) [----] I, [2016-04-15T09:35:01.887884 #29199:13e2d84] INFO -- : Rendered layouts/_page_header_navbar.html.haml (25.5ms) [----] I, [2016-04-15T09:35:01.888768 #29199:13e2d84] INFO -- : Rendered layouts/_spinner.html.haml (0.1ms) [----] I, [2016-04-15T09:35:01.889186 #29199:13e2d84] INFO -- : Rendered layouts/_lightbox_panel.html.haml (0.1ms) [----] I, [2016-04-15T09:35:01.889390 #29199:13e2d84] INFO -- : Rendered layouts/_header.html.haml (33.0ms) [----] I, [2016-04-15T09:35:01.890052 #29199:13e2d84] INFO -- : Rendered layouts/_breadcrumbs.html.haml (0.1ms) [----] I, [2016-04-15T09:35:01.890411 #29199:13e2d84] INFO -- : Rendered layouts/_content.html.haml (0.7ms) [----] I, [2016-04-15T09:35:01.890970 #29199:13e2d84] INFO -- : Rendered layouts/_adv_search.html.haml (0.1ms) [----] I, [2016-04-15T09:35:01.891208 #29199:13e2d84] INFO -- : Rendered layouts/_footer.html.haml (0.5ms) [----] I, [2016-04-15T09:35:01.891825 #29199:13e2d84] INFO -- : Completed 500 Internal Server Error in 232ms (Views: 71.7ms | ActiveRecord: 0.0ms)
Github link - https://github.com/ManageIQ/manageiq/issues/7956
https://github.com/ManageIQ/manageiq/pull/7979 fb3416ddacb62f8d060843663fc1d2729a420eec https://github.com/ManageIQ/manageiq/pull/7978 d31afaf1a72146f7571e19aae1b23c1b7c79c540
https://github.com/ManageIQ/manageiq/pull/8070
New commit detected on ManageIQ/manageiq/master: https://github.com/ManageIQ/manageiq/commit/909f06ff33c7f9fefc5b321069096c7d612ba6e8 commit 909f06ff33c7f9fefc5b321069096c7d612ba6e8 Author: Dávid Halász <dhalasz> AuthorDate: Tue Apr 19 09:43:11 2016 +0200 Commit: Dávid Halász <dhalasz> CommitDate: Tue Apr 19 16:27:29 2016 +0200 Release the DB connection after it's not needed in WebsocketServer https://bugzilla.redhat.com/show_bug.cgi?id=1327625 lib/websocket_server.rb | 3 +++ 1 file changed, 3 insertions(+)
Created attachment 1150562 [details] firefox
Created attachment 1150563 [details] chrome
Created attachment 1150564 [details] IE
Hi David, I tested work around on my setup as suggested by you and it works fine. But this seems to be a temporary fix for now to work with. Thanks, Ramesh
I'm confused, is "[JSON::GeneratorError] only generation of JSON objects or arrays allowed" fixed by one, two or all three of these PRs? https://github.com/ManageIQ/manageiq/pull/7979 https://github.com/ManageIQ/manageiq/pull/7978 https://github.com/ManageIQ/manageiq/pull/8070 What is the "HTML5 console now hangs" issue? https://bugzilla.redhat.com/show_bug.cgi?id=1327625#c6 It seems like we're bundling several issues in this BZ and I'm confused. Please fix a issue and open a new BZ for followup issues. With that said, I would ask is this with the above PRs all merged? Does it hang on the first request for the html5 consoles? Does it start happening after several good requests and then hang forever? Stopping/starting a worker fixing an issue indicates to me that we're hitting a bug in the console/worker code that we don't recover from and restarting the worker resets it back to a good state. David, were you able to recreate it with rake evm:start starting workers and fail to recreate it with starting the worker from rails console? It's good to try to eliminate rake evm:start vs. launching the worker via rails console but we have to ensure we have an exact recipe to recreate the problem in the rake evm:start setup. With that said, I don't see what the server forking processes would do to cause this problem. I would log all incoming rack requests using a rack middleware in the good/bad scenario and log the html5 consoles to see what's happening that's causing the worker to hang.
Good to go. Verified and working fine in 5.6.0.9-rc2.20160531154046_b4e2f6d
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2016:1348