Attachment 1483084 Details for Bug 1628632 – production.log

production.log

production.log (text/plain), 140.50 KB, created by Danylo Kholodov on 2018-09-13 15:22:43 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Danylo Kholodov

Created: 2018-09-13 15:22:43 UTC

Size: 140.50 KB

patch

obsolete

>[root@cfme-0 log]# tail -1000 production.log
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `find'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:665:in `generic_button_operation'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:507:in `terminatevms'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/explorer.rb:103:in `x_button'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:188:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:126:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:455:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rescue.rb:20:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `block in instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `instrument'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
>/opt/rh/cfme-gemset/gems/activerecord-5.0.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:126:in `process'
>/opt/rh/cfme-gemset/gems/actionview-5.0.7/lib/action_view/rendering.rb:30:in `process'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:190:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:262:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:32:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:39:in `block in serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `each'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:727:in `call'
>/opt/rh/cfme-gemset/bundler/gems/cfme-graphql-5f68621f2791/lib/manageiq/graphql/rest_api_proxy.rb:18: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.5/lib/rack/etag.rb:25:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/cookies.rb:613:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:36:in `call_app'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:26:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/request_id.rb:24:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/executor.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/engine.rb:522:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
>[----] I, [2018-09-13T09:42:05.143587 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exception_contents.html.haml (0.1ms)
>[----] I, [2018-09-13T09:42:05.144060 #12616:3c431ac]  INFO -- : Completed 200 OK in 256ms (Views: 1.0ms | ActiveRecord: 2.3ms)
>[----] I, [2018-09-13T09:42:09.676745 #12616:3c45b8c]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 09:42:09 -0400
>[----] I, [2018-09-13T09:42:09.679812 #12616:3c45b8c]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T09:42:09.713447 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:09.713897 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.1ms)
>[----] I, [2018-09-13T09:42:09.714827 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.6ms)
>[----] I, [2018-09-13T09:42:09.715017 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.9ms)
>[----] I, [2018-09-13T09:42:09.715763 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.5ms)
>[----] I, [2018-09-13T09:42:09.724941 #12616:3c45b8c]  INFO -- : Completed 200 OK in 45ms (Views: 7.0ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T09:42:10.147034 #12616:3c49ca0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:10 -0400
>[----] I, [2018-09-13T09:42:10.151070 #12616:3c49ca0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:10.151232 #12616:3c49ca0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:10.297562 #12616:3c49ca0]  INFO -- : Completed 200 OK in 146ms (Views: 6.9ms | ActiveRecord: 20.0ms)
>[----] I, [2018-09-13T09:42:11.702135 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 09:42:11 -0400
>[----] I, [2018-09-13T09:42:11.705169 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T09:42:11.739782 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.1ms)
>[----] I, [2018-09-13T09:42:11.740154 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:11.740954 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T09:42:11.741030 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.5ms)
>[----] I, [2018-09-13T09:42:11.741649 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.4ms)
>[----] I, [2018-09-13T09:42:11.750602 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 45ms (Views: 6.8ms | ActiveRecord: 3.7ms)
>[----] I, [2018-09-13T09:42:12.169470 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:12 -0400
>[----] I, [2018-09-13T09:42:12.173350 #12616:3c442dc]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:12.173518 #12616:3c442dc]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:12.336781 #12616:3c442dc]  INFO -- : Completed 200 OK in 163ms (Views: 7.2ms | ActiveRecord: 24.6ms)
>[----] I, [2018-09-13T09:42:13.557517 #12616:3c431ac]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 09:42:13 -0400
>[----] I, [2018-09-13T09:42:13.560854 #12616:3c431ac]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T09:42:13.594493 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:13.594889 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:13.595688 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T09:42:13.595794 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.6ms)
>[----] I, [2018-09-13T09:42:13.596560 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.4ms)
>[----] I, [2018-09-13T09:42:13.605777 #12616:3c431ac]  INFO -- : Completed 200 OK in 45ms (Views: 6.9ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T09:42:13.985998 #12616:3c45b8c]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:13 -0400
>[----] I, [2018-09-13T09:42:13.990134 #12616:3c45b8c]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:13.990265 #12616:3c45b8c]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:14.142958 #12616:3c45b8c]  INFO -- : Completed 200 OK in 153ms (Views: 6.8ms | ActiveRecord: 19.7ms)
>[----] I, [2018-09-13T09:42:27.925452 #12616:3c49ca0]  INFO -- : Started POST "/vm_cloud/x_button?pressed=instance_start" for 127.0.0.1 at 2018-09-13 09:42:27 -0400
>[----] I, [2018-09-13T09:42:27.929184 #12616:3c49ca0]  INFO -- : Processing by VmCloudController#x_button as JS
>[----] I, [2018-09-13T09:42:27.929246 #12616:3c49ca0]  INFO -- :   Parameters: {"miq_grid_checks"=>"41", "pressed"=>"instance_start"}
>[----] I, [2018-09-13T09:42:27.987065 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.1ms)
>[----] I, [2018-09-13T09:42:27.987440 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:27.988327 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.5ms)
>[----] I, [2018-09-13T09:42:27.988412 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.8ms)
>[----] I, [2018-09-13T09:42:27.989162 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.4ms)
>[----] I, [2018-09-13T09:42:27.999127 #12616:3c49ca0]  INFO -- : Completed 200 OK in 70ms (Views: 7.7ms | ActiveRecord: 7.2ms)
>[----] I, [2018-09-13T09:42:28.393930 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:28 -0400
>[----] I, [2018-09-13T09:42:28.397644 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:28.397773 #12616:3c3e5d0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:28.548441 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 151ms (Views: 6.7ms | ActiveRecord: 19.9ms)
>[----] I, [2018-09-13T09:42:32.758072 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:42:32 -0400
>[----] I, [2018-09-13T09:42:32.761068 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:42:32.795775 #12627:f362cc]  INFO -- : Completed 200 OK in 35ms (Views: 0.2ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T09:42:38.534631 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:42:38 -0400
>[----] I, [2018-09-13T09:42:38.537876 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:42:38.566166 #12627:f3497c]  INFO -- : Completed 200 OK in 28ms (Views: 0.2ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T09:42:39.066266 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 09:42:39 -0400
>[----] I, [2018-09-13T09:42:39.069605 #12616:3c442dc]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T09:42:39.106163 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:39.106561 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:39.107514 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.5ms)
>[----] I, [2018-09-13T09:42:39.107592 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.7ms)
>[----] I, [2018-09-13T09:42:39.108397 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.5ms)
>[----] I, [2018-09-13T09:42:39.119008 #12616:3c442dc]  INFO -- : Completed 200 OK in 49ms (Views: 7.9ms | ActiveRecord: 4.3ms)
>[----] I, [2018-09-13T09:42:39.687434 #12616:3c431ac]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:39 -0400
>[----] I, [2018-09-13T09:42:39.691262 #12616:3c431ac]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:39.691387 #12616:3c431ac]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:39.878799 #12616:3c431ac]  INFO -- : Completed 200 OK in 187ms (Views: 7.3ms | ActiveRecord: 21.1ms)
>[----] I, [2018-09-13T09:42:48.926290 #12616:3c45b8c]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 09:42:48 -0400
>[----] I, [2018-09-13T09:42:48.929665 #12616:3c45b8c]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T09:42:48.964502 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:48.964881 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:42:48.965811 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.6ms)
>[----] I, [2018-09-13T09:42:48.965959 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.8ms)
>[----] I, [2018-09-13T09:42:48.966883 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.5ms)
>[----] I, [2018-09-13T09:42:48.977230 #12616:3c45b8c]  INFO -- : Completed 200 OK in 47ms (Views: 7.8ms | ActiveRecord: 3.8ms)
>[----] I, [2018-09-13T09:42:49.387857 #12616:3c49ca0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:42:49 -0400
>[----] I, [2018-09-13T09:42:49.391423 #12616:3c49ca0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:42:49.391532 #12616:3c49ca0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:42:49.548515 #12616:3c49ca0]  INFO -- : Completed 200 OK in 157ms (Views: 7.1ms | ActiveRecord: 21.6ms)
>[----] I, [2018-09-13T09:43:01.191024 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/x_button?pressed=instance_terminate" for 127.0.0.1 at 2018-09-13 09:43:01 -0400
>[----] I, [2018-09-13T09:43:01.193932 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#x_button as JS
>[----] I, [2018-09-13T09:43:01.193999 #12616:3c3e5d0]  INFO -- :   Parameters: {"miq_grid_checks"=>"41", "pressed"=>"instance_terminate"}
>[----] F, [2018-09-13T09:43:01.453766 #12616:3c3e5d0] FATAL -- : Error caught: [NoMethodError] undefined method `validate_vm_destroy' for #<ManageIQ::Providers::Openstack::CloudManager::Vm:0x000000001ab706c8>
>Did you mean?  validate_stop
>/opt/rh/cfme-gemset/gems/activemodel-5.0.7/lib/active_model/attribute_methods.rb:433:in `method_missing'
>/var/www/miq/vmdb/app/models/mixins/availability_mixin.rb:24:in `is_available?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:219:in `block in records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `each'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `find'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:665:in `generic_button_operation'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:507:in `terminatevms'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/explorer.rb:103:in `x_button'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:188:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:126:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:455:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rescue.rb:20:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `block in instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `instrument'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
>/opt/rh/cfme-gemset/gems/activerecord-5.0.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:126:in `process'
>/opt/rh/cfme-gemset/gems/actionview-5.0.7/lib/action_view/rendering.rb:30:in `process'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:190:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:262:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:32:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:39:in `block in serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `each'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:727:in `call'
>/opt/rh/cfme-gemset/bundler/gems/cfme-graphql-5f68621f2791/lib/manageiq/graphql/rest_api_proxy.rb:18: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.5/lib/rack/etag.rb:25:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/cookies.rb:613:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:36:in `call_app'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:26:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/request_id.rb:24:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/executor.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/engine.rb:522:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
>[----] I, [2018-09-13T09:43:01.455179 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exception_contents.html.haml (0.2ms)
>[----] I, [2018-09-13T09:43:01.455700 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 262ms (Views: 1.2ms | ActiveRecord: 2.6ms)
>[----] I, [2018-09-13T09:43:35.510599 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:43:35 -0400
>[----] I, [2018-09-13T09:43:35.513443 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:43:35.539416 #12627:f3820c]  INFO -- : Completed 200 OK in 26ms (Views: 0.1ms | ActiveRecord: 2.7ms)
>[----] I, [2018-09-13T09:43:37.916243 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:43:37 -0400
>[----] I, [2018-09-13T09:43:37.919301 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:43:37.947263 #12627:f35dcc]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 3.0ms)
>[----] I, [2018-09-13T09:44:35.511946 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:44:35 -0400
>[----] I, [2018-09-13T09:44:35.515021 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:44:35.545022 #12627:f30ffc]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T09:44:37.916904 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:44:37 -0400
>[----] I, [2018-09-13T09:44:37.919800 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:44:37.946157 #12627:f362cc]  INFO -- : Completed 200 OK in 26ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T09:44:43.884445 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/x_button?pressed=instance_terminate" for 127.0.0.1 at 2018-09-13 09:44:43 -0400
>[----] I, [2018-09-13T09:44:43.887794 #12616:3c442dc]  INFO -- : Processing by VmCloudController#x_button as JS
>[----] I, [2018-09-13T09:44:43.887863 #12616:3c442dc]  INFO -- :   Parameters: {"miq_grid_checks"=>"41", "pressed"=>"instance_terminate"}
>[----] F, [2018-09-13T09:44:44.139773 #12616:3c442dc] FATAL -- : Error caught: [NoMethodError] undefined method `validate_vm_destroy' for #<ManageIQ::Providers::Openstack::CloudManager::Vm:0x000000001a5f7598>
>Did you mean?  validate_stop
>/opt/rh/cfme-gemset/gems/activemodel-5.0.7/lib/active_model/attribute_methods.rb:433:in `method_missing'
>/var/www/miq/vmdb/app/models/mixins/availability_mixin.rb:24:in `is_available?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:219:in `block in records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `each'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `find'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:665:in `generic_button_operation'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:507:in `terminatevms'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/explorer.rb:103:in `x_button'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:188:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:126:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:455:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rescue.rb:20:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `block in instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `instrument'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
>/opt/rh/cfme-gemset/gems/activerecord-5.0.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:126:in `process'
>/opt/rh/cfme-gemset/gems/actionview-5.0.7/lib/action_view/rendering.rb:30:in `process'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:190:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:262:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:32:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:39:in `block in serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `each'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:727:in `call'
>/opt/rh/cfme-gemset/bundler/gems/cfme-graphql-5f68621f2791/lib/manageiq/graphql/rest_api_proxy.rb:18: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.5/lib/rack/etag.rb:25:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/cookies.rb:613:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:36:in `call_app'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:26:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/request_id.rb:24:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/executor.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/engine.rb:522:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
>[----] I, [2018-09-13T09:44:44.143706 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exception_contents.html.haml (2.6ms)
>[----] I, [2018-09-13T09:44:44.144169 #12616:3c442dc]  INFO -- : Completed 200 OK in 256ms (Views: 3.5ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T09:45:37.802488 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:45:37 -0400
>[----] I, [2018-09-13T09:45:37.805331 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:45:37.833408 #12627:f3497c]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T09:45:38.127936 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:45:38 -0400
>[----] I, [2018-09-13T09:45:38.131085 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:45:38.160248 #12627:f3820c]  INFO -- : Completed 200 OK in 29ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T09:46:37.504017 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:46:37 -0400
>[----] I, [2018-09-13T09:46:37.507539 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:46:37.546215 #12627:f35dcc]  INFO -- : Completed 200 OK in 39ms (Views: 0.1ms | ActiveRecord: 4.1ms)
>[----] I, [2018-09-13T09:46:37.918901 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:46:37 -0400
>[----] I, [2018-09-13T09:46:37.922131 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:46:37.951257 #12627:f30ffc]  INFO -- : Completed 200 OK in 29ms (Views: 0.2ms | ActiveRecord: 3.1ms)
>[----] I, [2018-09-13T09:47:37.504553 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:47:37 -0400
>[----] I, [2018-09-13T09:47:37.507429 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:47:37.542439 #12627:f362cc]  INFO -- : Completed 200 OK in 35ms (Views: 0.2ms | ActiveRecord: 3.5ms)
>[----] I, [2018-09-13T09:47:37.920986 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:47:37 -0400
>[----] I, [2018-09-13T09:47:37.923989 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:47:37.954700 #12627:f3497c]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T09:48:37.508760 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:48:37 -0400
>[----] I, [2018-09-13T09:48:37.512308 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:48:37.550370 #12627:f3820c]  INFO -- : Completed 200 OK in 38ms (Views: 0.2ms | ActiveRecord: 5.5ms)
>[----] I, [2018-09-13T09:48:37.921013 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:48:37 -0400
>[----] I, [2018-09-13T09:48:37.924340 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:48:37.953408 #12627:f35dcc]  INFO -- : Completed 200 OK in 29ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T09:49:37.507623 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:49:37 -0400
>[----] I, [2018-09-13T09:49:37.512197 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:49:37.544900 #12627:f30ffc]  INFO -- : Completed 200 OK in 33ms (Views: 0.1ms | ActiveRecord: 3.3ms)
>[----] I, [2018-09-13T09:49:37.923509 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:49:37 -0400
>[----] I, [2018-09-13T09:49:37.927215 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:49:37.958452 #12627:f362cc]  INFO -- : Completed 200 OK in 31ms (Views: 0.1ms | ActiveRecord: 3.0ms)
>[----] I, [2018-09-13T09:50:00.578116 #12616:3c431ac]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 09:50:00 -0400
>[----] I, [2018-09-13T09:50:00.581515 #12616:3c431ac]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T09:50:00.643428 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T09:50:00.644275 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.6ms)
>[----] I, [2018-09-13T09:50:00.645056 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.6ms)
>[----] I, [2018-09-13T09:50:00.645141 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.7ms)
>[----] I, [2018-09-13T09:50:00.645545 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.645841 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.646563 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.2ms)
>[----] I, [2018-09-13T09:50:00.646665 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T09:50:00.646749 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.2ms)
>[----] I, [2018-09-13T09:50:00.646958 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.647626 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.648747 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.649952 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (0.9ms)
>[----] I, [2018-09-13T09:50:00.653379 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (2.7ms)
>[----] I, [2018-09-13T09:50:00.653653 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T09:50:00.653854 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.653995 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.654139 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.654214 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.3ms)
>[----] I, [2018-09-13T09:50:00.671664 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (17.2ms)
>[----] I, [2018-09-13T09:50:00.695252 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (23.3ms)
>[----] I, [2018-09-13T09:50:00.696217 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.697760 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.2ms)
>[----] I, [2018-09-13T09:50:00.697845 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.5ms)
>[----] I, [2018-09-13T09:50:00.697963 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (43.6ms)
>[----] I, [2018-09-13T09:50:00.701205 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:50:00.703079 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.7ms)
>[----] I, [2018-09-13T09:50:00.703232 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (2.1ms)
>[----] I, [2018-09-13T09:50:00.703311 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.9ms)
>[----] I, [2018-09-13T09:50:00.706174 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.7ms)
>[----] I, [2018-09-13T09:50:00.706261 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (8.0ms)
>[----] I, [2018-09-13T09:50:00.706352 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (8.1ms)
>[----] I, [2018-09-13T09:50:00.708847 #12616:3c431ac]  INFO -- : Completed 200 OK in 127ms (Views: 59.3ms | ActiveRecord: 11.7ms)
>[----] I, [2018-09-13T09:50:11.639748 #12616:3c45b8c]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 09:50:11 -0400
>[----] I, [2018-09-13T09:50:11.643078 #12616:3c45b8c]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:50:11.643166 #12616:3c45b8c]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T09:50:11.643803 #12616:3c45b8c]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T09:50:11.644092 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.2ms)
>[----] I, [2018-09-13T09:50:11.644324 #12616:3c45b8c]  INFO -- : Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:50:12.211623 #12627:f3497c]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 09:50:12 -0400
>[----] I, [2018-09-13T09:50:12.215047 #12627:f3497c]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T09:50:12.215140 #12627:f3497c]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T09:50:12.251621 #12627:f3497c]  INFO -- : Completed 200 OK in 36ms (Views: 0.1ms | ActiveRecord: 6.2ms)
>[----] I, [2018-09-13T09:50:12.266789 #12616:3c49ca0]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 09:50:12 -0400
>[----] I, [2018-09-13T09:50:12.268923 #12616:3c3e5d0]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 09:50:12 -0400
>[----] I, [2018-09-13T09:50:12.270677 #12616:3c3e5d0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:50:12.271254 #12616:3c49ca0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:50:12.271381 #12616:3c3e5d0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T09:50:12.271479 #12616:3c49ca0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T09:50:12.272135 #12616:3c3e5d0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T09:50:12.272564 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T09:50:12.272747 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.1ms)
>[----] I, [2018-09-13T09:50:12.272933 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.1ms)
>[----] I, [2018-09-13T09:50:12.273135 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 2ms (Views: 1.2ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:50:12.273308 #12616:3c49ca0]  INFO -- : Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:50:12.396797 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:50:12 -0400
>[----] I, [2018-09-13T09:50:12.400612 #12616:3c442dc]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:50:12.400764 #12616:3c442dc]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:50:12.584658 #12616:3c442dc]  INFO -- : Completed 200 OK in 184ms (Views: 7.0ms | ActiveRecord: 24.6ms)
>[----] I, [2018-09-13T09:50:38.808847 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:50:38 -0400
>[----] I, [2018-09-13T09:50:38.812175 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:50:38.843404 #12627:f3820c]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T09:51:12.516908 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:51:12 -0400
>[----] I, [2018-09-13T09:51:12.520257 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:51:12.548535 #12627:f35dcc]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T09:51:38.515735 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:51:38 -0400
>[----] I, [2018-09-13T09:51:38.520541 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:51:38.562126 #12627:f30ffc]  INFO -- : Completed 200 OK in 41ms (Views: 0.2ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T09:52:12.514485 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:52:12 -0400
>[----] I, [2018-09-13T09:52:12.518016 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:52:12.551760 #12627:f362cc]  INFO -- : Completed 200 OK in 34ms (Views: 0.1ms | ActiveRecord: 3.5ms)
>[----] I, [2018-09-13T09:52:38.516889 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:52:38 -0400
>[----] I, [2018-09-13T09:52:38.519993 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:52:38.549192 #12627:f3497c]  INFO -- : Completed 200 OK in 29ms (Views: 0.2ms | ActiveRecord: 3.1ms)
>[----] I, [2018-09-13T09:53:12.512929 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:53:12 -0400
>[----] I, [2018-09-13T09:53:12.515813 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:53:12.546419 #12627:f3820c]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T09:53:38.512159 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:53:38 -0400
>[----] I, [2018-09-13T09:53:38.515888 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:53:38.547685 #12627:f35dcc]  INFO -- : Completed 200 OK in 32ms (Views: 0.1ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T09:54:12.515438 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:54:12 -0400
>[----] I, [2018-09-13T09:54:12.518311 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:54:12.544979 #12627:f30ffc]  INFO -- : Completed 200 OK in 27ms (Views: 0.2ms | ActiveRecord: 2.7ms)
>[----] I, [2018-09-13T09:54:38.515053 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:54:38 -0400
>[----] I, [2018-09-13T09:54:38.518408 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:54:38.549285 #12627:f362cc]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 3.3ms)
>[----] I, [2018-09-13T09:55:12.513501 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:55:12 -0400
>[----] I, [2018-09-13T09:55:12.517143 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:55:12.550052 #12627:f3497c]  INFO -- : Completed 200 OK in 33ms (Views: 0.2ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T09:55:38.513792 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:55:38 -0400
>[----] I, [2018-09-13T09:55:38.517162 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:55:38.545522 #12627:f3820c]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T09:56:12.812574 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:56:12 -0400
>[----] I, [2018-09-13T09:56:12.815530 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:56:12.842588 #12627:f35dcc]  INFO -- : Completed 200 OK in 27ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T09:56:38.515383 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:56:38 -0400
>[----] I, [2018-09-13T09:56:38.519015 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:56:38.546797 #12627:f30ffc]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T09:57:12.522994 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:57:12 -0400
>[----] I, [2018-09-13T09:57:12.526578 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:57:12.557970 #12627:f362cc]  INFO -- : Completed 200 OK in 31ms (Views: 0.1ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T09:57:38.518597 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:57:38 -0400
>[----] I, [2018-09-13T09:57:38.522252 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:57:38.555166 #12627:f3497c]  INFO -- : Completed 200 OK in 33ms (Views: 0.1ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T09:58:12.517211 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:58:12 -0400
>[----] I, [2018-09-13T09:58:12.520372 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:58:12.549874 #12627:f3820c]  INFO -- : Completed 200 OK in 29ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T09:58:38.519271 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:58:38 -0400
>[----] I, [2018-09-13T09:58:38.522527 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:58:38.549789 #12627:f35dcc]  INFO -- : Completed 200 OK in 27ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T09:59:04.027875 #12616:3c431ac]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 09:59:04 -0400
>[----] I, [2018-09-13T09:59:04.031478 #12616:3c431ac]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T09:59:04.114857 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T09:59:04.115755 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.6ms)
>[----] I, [2018-09-13T09:59:04.116597 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.5ms)
>[----] I, [2018-09-13T09:59:04.116682 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.8ms)
>[----] I, [2018-09-13T09:59:04.117117 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.117404 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.118196 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.2ms)
>[----] I, [2018-09-13T09:59:04.118279 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T09:59:04.118346 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.3ms)
>[----] I, [2018-09-13T09:59:04.118525 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.119273 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.120423 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.121689 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (1.0ms)
>[----] I, [2018-09-13T09:59:04.125435 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (3.0ms)
>[----] I, [2018-09-13T09:59:04.125695 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T09:59:04.125874 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.126026 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.126179 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.126250 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.6ms)
>[----] I, [2018-09-13T09:59:04.144017 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (17.5ms)
>[----] I, [2018-09-13T09:59:04.166674 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (22.4ms)
>[----] I, [2018-09-13T09:59:04.167512 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.168878 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.0ms)
>[----] I, [2018-09-13T09:59:04.168986 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.3ms)
>[----] I, [2018-09-13T09:59:04.169112 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (42.7ms)
>[----] I, [2018-09-13T09:59:04.172164 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:04.173848 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.6ms)
>[----] I, [2018-09-13T09:59:04.173941 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (1.9ms)
>[----] I, [2018-09-13T09:59:04.174018 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.5ms)
>[----] I, [2018-09-13T09:59:04.176762 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.6ms)
>[----] I, [2018-09-13T09:59:04.176847 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (7.5ms)
>[----] I, [2018-09-13T09:59:04.176940 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (7.7ms)
>[----] I, [2018-09-13T09:59:04.179225 #12616:3c431ac]  INFO -- : Completed 200 OK in 148ms (Views: 58.1ms | ActiveRecord: 16.1ms)
>[----] I, [2018-09-13T09:59:10.566927 #12616:3c45b8c]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 09:59:10 -0400
>[----] I, [2018-09-13T09:59:10.570061 #12616:3c45b8c]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:59:10.570149 #12616:3c45b8c]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T09:59:10.570788 #12616:3c45b8c]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T09:59:10.570984 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T09:59:10.571196 #12616:3c45b8c]  INFO -- : Completed 200 OK in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:59:10.826388 #12616:3c3e5d0]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 09:59:10 -0400
>[----] I, [2018-09-13T09:59:10.829192 #12616:3c3e5d0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:59:10.829302 #12616:3c3e5d0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T09:59:10.829870 #12616:3c3e5d0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T09:59:10.830005 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:10.830191 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 1ms (Views: 0.5ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:59:10.831245 #12616:3c49ca0]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 09:59:10 -0400
>[----] I, [2018-09-13T09:59:10.832752 #12616:3c49ca0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T09:59:10.832822 #12616:3c49ca0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T09:59:10.833168 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T09:59:10.833298 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.0ms)
>[----] I, [2018-09-13T09:59:10.833440 #12616:3c49ca0]  INFO -- : Completed 200 OK in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T09:59:11.014902 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 09:59:11 -0400
>[----] I, [2018-09-13T09:59:11.019391 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T09:59:11.019522 #12616:3c3e5d0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T09:59:11.044337 #12627:f30ffc]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 09:59:11 -0400
>[----] I, [2018-09-13T09:59:11.047867 #12627:f30ffc]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T09:59:11.047939 #12627:f30ffc]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T09:59:11.080126 #12627:f30ffc]  INFO -- : Completed 200 OK in 32ms (Views: 0.2ms | ActiveRecord: 5.8ms)
>[----] I, [2018-09-13T09:59:11.170309 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 151ms (Views: 6.3ms | ActiveRecord: 20.6ms)
>[----] I, [2018-09-13T09:59:38.521646 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 09:59:38 -0400
>[----] I, [2018-09-13T09:59:38.524479 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T09:59:38.550591 #12627:f362cc]  INFO -- : Completed 200 OK in 26ms (Views: 0.1ms | ActiveRecord: 3.0ms)
>[----] I, [2018-09-13T10:00:11.519704 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:00:11 -0400
>[----] I, [2018-09-13T10:00:11.522875 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:00:11.551536 #12627:f3497c]  INFO -- : Completed 200 OK in 29ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T10:00:38.519582 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:00:38 -0400
>[----] I, [2018-09-13T10:00:38.522673 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:00:38.552820 #12627:f3820c]  INFO -- : Completed 200 OK in 30ms (Views: 0.2ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:01:11.521244 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:01:11 -0400
>[----] I, [2018-09-13T10:01:11.524108 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:01:11.550502 #12627:f35dcc]  INFO -- : Completed 200 OK in 26ms (Views: 0.2ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T10:01:34.022255 #12616:3c442dc]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 10:01:34 -0400
>[----] I, [2018-09-13T10:01:34.025061 #12616:3c442dc]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T10:01:34.082412 #12616:3c442dc]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T10:01:34.083270 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.6ms)
>[----] I, [2018-09-13T10:01:34.084012 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.5ms)
>[----] I, [2018-09-13T10:01:34.084092 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.7ms)
>[----] I, [2018-09-13T10:01:34.084499 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.084807 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.085492 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.2ms)
>[----] I, [2018-09-13T10:01:34.085571 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.3ms)
>[----] I, [2018-09-13T10:01:34.085661 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.1ms)
>[----] I, [2018-09-13T10:01:34.085844 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.086494 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.087568 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.088755 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (0.9ms)
>[----] I, [2018-09-13T10:01:34.092290 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (2.8ms)
>[----] I, [2018-09-13T10:01:34.092546 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:34.092743 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.092894 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.093058 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.093126 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.4ms)
>[----] I, [2018-09-13T10:01:34.104039 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (10.7ms)
>[----] I, [2018-09-13T10:01:34.124826 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (20.5ms)
>[----] I, [2018-09-13T10:01:34.125553 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.126856 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.0ms)
>[----] I, [2018-09-13T10:01:34.126942 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.2ms)
>[----] I, [2018-09-13T10:01:34.127073 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (33.8ms)
>[----] I, [2018-09-13T10:01:34.129927 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:34.131452 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.6ms)
>[----] I, [2018-09-13T10:01:34.131537 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (1.8ms)
>[----] I, [2018-09-13T10:01:34.131612 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.2ms)
>[----] I, [2018-09-13T10:01:34.134258 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.5ms)
>[----] I, [2018-09-13T10:01:34.134357 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (7.1ms)
>[----] I, [2018-09-13T10:01:34.134452 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (7.2ms)
>[----] I, [2018-09-13T10:01:34.136693 #12616:3c442dc]  INFO -- : Completed 200 OK in 112ms (Views: 50.2ms | ActiveRecord: 9.4ms)
>[----] I, [2018-09-13T10:01:37.639489 #12616:3c431ac]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 10:01:37 -0400
>[----] I, [2018-09-13T10:01:37.642423 #12616:3c431ac]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:37.642508 #12616:3c431ac]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T10:01:37.643138 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T10:01:37.643343 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:37.643530 #12616:3c431ac]  INFO -- : Completed 200 OK in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:37.994062 #12616:3c45b8c]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 10:01:37 -0400
>[----] I, [2018-09-13T10:01:37.997011 #12616:3c45b8c]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:37.997090 #12616:3c45b8c]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T10:01:37.997603 #12616:3c45b8c]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T10:01:37.997810 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:37.997986 #12616:3c45b8c]  INFO -- : Completed 200 OK in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:37.999461 #12616:3c49ca0]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 10:01:37 -0400
>[----] I, [2018-09-13T10:01:38.001373 #12616:3c49ca0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:38.001443 #12616:3c49ca0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T10:01:38.001872 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T10:01:38.001981 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:38.002154 #12616:3c49ca0]  INFO -- : Completed 200 OK in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:38.047269 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 10:01:38 -0400
>[----] I, [2018-09-13T10:01:38.050872 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T10:01:38.050980 #12616:3c3e5d0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T10:01:38.204217 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 153ms (Views: 6.0ms | ActiveRecord: 22.5ms)
>[----] I, [2018-09-13T10:01:38.521647 #12627:f30ffc]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 10:01:38 -0400
>[----] I, [2018-09-13T10:01:38.525068 #12627:f30ffc]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T10:01:38.525191 #12627:f30ffc]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T10:01:38.572423 #12627:f30ffc]  INFO -- : Completed 200 OK in 47ms (Views: 0.2ms | ActiveRecord: 5.9ms)
>[----] I, [2018-09-13T10:01:38.673351 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:01:38 -0400
>[----] I, [2018-09-13T10:01:38.676498 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:01:38.707530 #12627:f362cc]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:01:49.107049 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/x_button?pressed=instance_terminate" for 127.0.0.1 at 2018-09-13 10:01:49 -0400
>[----] I, [2018-09-13T10:01:49.111210 #12616:3c442dc]  INFO -- : Processing by VmCloudController#x_button as JS
>[----] I, [2018-09-13T10:01:49.111351 #12616:3c442dc]  INFO -- :   Parameters: {"miq_grid_checks"=>"41", "pressed"=>"instance_terminate"}
>[----] F, [2018-09-13T10:01:49.407045 #12616:3c442dc] FATAL -- : Error caught: [NoMethodError] undefined method `validate_vm_destroy' for #<ManageIQ::Providers::Openstack::CloudManager::Vm:0x0000000017a59a08>
>Did you mean?  validate_stop
>/opt/rh/cfme-gemset/gems/activemodel-5.0.7/lib/active_model/attribute_methods.rb:433:in `method_missing'
>/var/www/miq/vmdb/app/models/mixins/availability_mixin.rb:24:in `is_available?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:219:in `block in records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `each'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `find'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:665:in `generic_button_operation'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:507:in `terminatevms'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/explorer.rb:103:in `x_button'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:188:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:126:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:455:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rescue.rb:20:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `block in instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `instrument'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
>/opt/rh/cfme-gemset/gems/activerecord-5.0.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:126:in `process'
>/opt/rh/cfme-gemset/gems/actionview-5.0.7/lib/action_view/rendering.rb:30:in `process'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:190:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:262:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:32:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:39:in `block in serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `each'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:727:in `call'
>/opt/rh/cfme-gemset/bundler/gems/cfme-graphql-5f68621f2791/lib/manageiq/graphql/rest_api_proxy.rb:18: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.5/lib/rack/etag.rb:25:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/cookies.rb:613:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:36:in `call_app'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:26:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/request_id.rb:24:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/executor.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/engine.rb:522:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
>[----] I, [2018-09-13T10:01:49.408524 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exception_contents.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:49.409035 #12616:3c442dc]  INFO -- : Completed 200 OK in 298ms (Views: 1.1ms | ActiveRecord: 4.5ms)
>[----] I, [2018-09-13T10:01:52.983359 #12616:3c431ac]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 10:01:52 -0400
>[----] I, [2018-09-13T10:01:52.986091 #12616:3c431ac]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T10:01:53.042143 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T10:01:53.043007 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.6ms)
>[----] I, [2018-09-13T10:01:53.043684 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.4ms)
>[----] I, [2018-09-13T10:01:53.043784 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.6ms)
>[----] I, [2018-09-13T10:01:53.044236 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.044528 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.045357 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.3ms)
>[----] I, [2018-09-13T10:01:53.045471 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.5ms)
>[----] I, [2018-09-13T10:01:53.045570 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.3ms)
>[----] I, [2018-09-13T10:01:53.045759 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.046784 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.048117 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.049279 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (0.9ms)
>[----] I, [2018-09-13T10:01:53.052893 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (2.7ms)
>[----] I, [2018-09-13T10:01:53.053282 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:53.053515 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.053826 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:53.054065 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:53.054140 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.8ms)
>[----] I, [2018-09-13T10:01:53.069931 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (15.5ms)
>[----] I, [2018-09-13T10:01:53.092914 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (22.6ms)
>[----] I, [2018-09-13T10:01:53.093641 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:53.095138 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.1ms)
>[----] I, [2018-09-13T10:01:53.095224 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.3ms)
>[----] I, [2018-09-13T10:01:53.095348 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (41.1ms)
>[----] I, [2018-09-13T10:01:53.098704 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:53.100464 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.7ms)
>[----] I, [2018-09-13T10:01:53.100550 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (2.0ms)
>[----] I, [2018-09-13T10:01:53.100616 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.9ms)
>[----] I, [2018-09-13T10:01:53.103695 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.9ms)
>[----] I, [2018-09-13T10:01:53.103833 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (8.2ms)
>[----] I, [2018-09-13T10:01:53.103977 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (8.4ms)
>[----] I, [2018-09-13T10:01:53.106282 #12616:3c431ac]  INFO -- : Completed 200 OK in 120ms (Views: 60.0ms | ActiveRecord: 9.4ms)
>[----] I, [2018-09-13T10:01:55.435004 #12616:3c45b8c]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 10:01:55 -0400
>[----] I, [2018-09-13T10:01:55.438066 #12616:3c45b8c]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:55.438133 #12616:3c45b8c]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T10:01:55.438783 #12616:3c45b8c]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T10:01:55.438977 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:01:55.439182 #12616:3c45b8c]  INFO -- : Completed 200 OK in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:55.740032 #12616:3c49ca0]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 10:01:55 -0400
>[----] I, [2018-09-13T10:01:55.742844 #12616:3c49ca0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:55.742909 #12616:3c49ca0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T10:01:55.743394 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T10:01:55.743573 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:55.743754 #12616:3c49ca0]  INFO -- : Completed 200 OK in 1ms (Views: 0.5ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:55.745141 #12616:3c3e5d0]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 10:01:55 -0400
>[----] I, [2018-09-13T10:01:55.746589 #12616:3c3e5d0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:01:55.746656 #12616:3c3e5d0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T10:01:55.747047 #12616:3c3e5d0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T10:01:55.747173 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.0ms)
>[----] I, [2018-09-13T10:01:55.747313 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:01:55.871899 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 10:01:55 -0400
>[----] I, [2018-09-13T10:01:55.875754 #12616:3c442dc]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T10:01:55.875909 #12616:3c442dc]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T10:01:56.019629 #12627:f3497c]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 10:01:56 -0400
>[----] I, [2018-09-13T10:01:56.023075 #12627:f3497c]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T10:01:56.023161 #12627:f3497c]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T10:01:56.065584 #12616:3c442dc]  INFO -- : Completed 200 OK in 190ms (Views: 6.4ms | ActiveRecord: 45.6ms)
>[----] I, [2018-09-13T10:01:56.089877 #12627:f3497c]  INFO -- : Completed 200 OK in 67ms (Views: 0.1ms | ActiveRecord: 29.1ms)
>[----] I, [2018-09-13T10:02:38.525812 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:02:38 -0400
>[----] I, [2018-09-13T10:02:38.528840 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:02:38.565021 #12627:f3820c]  INFO -- : Completed 200 OK in 36ms (Views: 0.2ms | ActiveRecord: 4.0ms)
>[----] I, [2018-09-13T10:02:56.525321 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:02:56 -0400
>[----] I, [2018-09-13T10:02:56.530173 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:02:56.561683 #12627:f35dcc]  INFO -- : Completed 200 OK in 31ms (Views: 0.1ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T10:03:38.524109 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:03:38 -0400
>[----] I, [2018-09-13T10:03:38.527183 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:03:38.555243 #12627:f30ffc]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T10:03:56.528862 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:03:56 -0400
>[----] I, [2018-09-13T10:03:56.532745 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:03:56.563107 #12627:f362cc]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.0ms)
>[----] I, [2018-09-13T10:04:38.532143 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:04:38 -0400
>[----] I, [2018-09-13T10:04:38.535439 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:04:38.568280 #12627:f3497c]  INFO -- : Completed 200 OK in 33ms (Views: 0.2ms | ActiveRecord: 4.6ms)
>[----] I, [2018-09-13T10:04:56.525312 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:04:56 -0400
>[----] I, [2018-09-13T10:04:56.528801 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:04:56.571062 #12627:f3820c]  INFO -- : Completed 200 OK in 42ms (Views: 0.2ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T10:05:38.533154 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:05:38 -0400
>[----] I, [2018-09-13T10:05:38.537251 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:05:38.569891 #12627:f35dcc]  INFO -- : Completed 200 OK in 32ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T10:05:56.531881 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:05:56 -0400
>[----] I, [2018-09-13T10:05:56.534985 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:05:56.567267 #12627:f30ffc]  INFO -- : Completed 200 OK in 32ms (Views: 0.1ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T10:06:38.535679 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:06:38 -0400
>[----] I, [2018-09-13T10:06:38.539690 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:06:38.572967 #12627:f362cc]  INFO -- : Completed 200 OK in 33ms (Views: 0.1ms | ActiveRecord: 2.8ms)
>[----] I, [2018-09-13T10:06:56.826286 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:06:56 -0400
>[----] I, [2018-09-13T10:06:56.829207 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:06:56.864567 #12627:f3497c]  INFO -- : Completed 200 OK in 35ms (Views: 0.2ms | ActiveRecord: 3.5ms)
>[----] I, [2018-09-13T10:07:38.528219 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:07:38 -0400
>[----] I, [2018-09-13T10:07:38.531166 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:07:38.557620 #12627:f3820c]  INFO -- : Completed 200 OK in 26ms (Views: 0.1ms | ActiveRecord: 2.6ms)
>[----] I, [2018-09-13T10:07:56.530673 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:07:56 -0400
>[----] I, [2018-09-13T10:07:56.533906 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:07:56.564478 #12627:f35dcc]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.6ms)
>[----] I, [2018-09-13T10:08:38.530399 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:08:38 -0400
>[----] I, [2018-09-13T10:08:38.533859 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:08:38.564905 #12627:f30ffc]  INFO -- : Completed 200 OK in 31ms (Views: 0.1ms | ActiveRecord: 3.0ms)
>[----] I, [2018-09-13T10:08:56.530251 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:08:56 -0400
>[----] I, [2018-09-13T10:08:56.533337 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:08:56.563033 #12627:f362cc]  INFO -- : Completed 200 OK in 30ms (Views: 0.2ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:09:38.529856 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:09:38 -0400
>[----] I, [2018-09-13T10:09:38.533519 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:09:38.563348 #12627:f3497c]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.4ms)
>[----] I, [2018-09-13T10:09:56.531760 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:09:56 -0400
>[----] I, [2018-09-13T10:09:56.535173 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:09:56.573317 #12627:f3820c]  INFO -- : Completed 200 OK in 38ms (Views: 0.1ms | ActiveRecord: 4.1ms)
>[----] I, [2018-09-13T10:10:38.536428 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:10:38 -0400
>[----] I, [2018-09-13T10:10:38.540368 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:10:38.572426 #12627:f35dcc]  INFO -- : Completed 200 OK in 32ms (Views: 0.2ms | ActiveRecord: 3.2ms)
>[----] I, [2018-09-13T10:10:56.538526 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:10:56 -0400
>[----] I, [2018-09-13T10:10:56.542068 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:10:56.571043 #12627:f30ffc]  INFO -- : Completed 200 OK in 29ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:11:09.616356 #12616:3c431ac]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 10:11:09 -0400
>[----] I, [2018-09-13T10:11:09.621063 #12616:3c431ac]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T10:11:09.698757 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T10:11:09.699578 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.5ms)
>[----] I, [2018-09-13T10:11:09.700362 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.5ms)
>[----] I, [2018-09-13T10:11:09.700442 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.7ms)
>[----] I, [2018-09-13T10:11:09.700911 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.701172 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.701913 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.2ms)
>[----] I, [2018-09-13T10:11:09.701995 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T10:11:09.702058 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.2ms)
>[----] I, [2018-09-13T10:11:09.702264 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.702943 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.704160 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.705341 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (0.9ms)
>[----] I, [2018-09-13T10:11:09.708797 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (2.6ms)
>[----] I, [2018-09-13T10:11:09.709026 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:09.709215 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.709371 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.709518 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.709618 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.3ms)
>[----] I, [2018-09-13T10:11:09.727150 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (17.3ms)
>[----] I, [2018-09-13T10:11:09.748778 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (21.4ms)
>[----] I, [2018-09-13T10:11:09.749558 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.750828 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.0ms)
>[----] I, [2018-09-13T10:11:09.750926 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.2ms)
>[----] I, [2018-09-13T10:11:09.751049 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (41.3ms)
>[----] I, [2018-09-13T10:11:09.754096 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:09.755686 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.6ms)
>[----] I, [2018-09-13T10:11:09.755829 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (1.9ms)
>[----] I, [2018-09-13T10:11:09.755896 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.5ms)
>[----] I, [2018-09-13T10:11:09.758693 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.7ms)
>[----] I, [2018-09-13T10:11:09.758796 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (7.5ms)
>[----] I, [2018-09-13T10:11:09.758883 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (7.7ms)
>[----] I, [2018-09-13T10:11:09.761213 #12616:3c431ac]  INFO -- : Completed 200 OK in 140ms (Views: 56.7ms | ActiveRecord: 12.4ms)
>[----] I, [2018-09-13T10:11:16.298847 #12616:3c45b8c]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 10:11:16 -0400
>[----] I, [2018-09-13T10:11:16.301642 #12616:3c45b8c]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:16.301741 #12616:3c45b8c]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T10:11:16.302405 #12616:3c45b8c]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T10:11:16.302600 #12616:3c45b8c]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:16.302809 #12616:3c45b8c]  INFO -- : Completed 200 OK in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:16.667082 #12616:3c49ca0]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 10:11:16 -0400
>[----] I, [2018-09-13T10:11:16.669990 #12616:3c49ca0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:16.670050 #12616:3c49ca0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T10:11:16.670549 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T10:11:16.670753 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:16.670930 #12616:3c49ca0]  INFO -- : Completed 200 OK in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:16.671541 #12616:3c3e5d0]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 10:11:16 -0400
>[----] I, [2018-09-13T10:11:16.673565 #12616:3c3e5d0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:16.674004 #12616:3c3e5d0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T10:11:16.674410 #12616:3c3e5d0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T10:11:16.674584 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:16.677534 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 3ms (Views: 3.2ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:16.846656 #12616:3c3e5d0]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 10:11:16 -0400
>[----] I, [2018-09-13T10:11:16.850839 #12616:3c3e5d0]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T10:11:16.850964 #12616:3c3e5d0]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T10:11:16.870174 #12627:f362cc]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 10:11:16 -0400
>[----] I, [2018-09-13T10:11:16.873529 #12627:f362cc]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T10:11:16.873598 #12627:f362cc]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T10:11:16.906192 #12627:f362cc]  INFO -- : Completed 200 OK in 32ms (Views: 0.2ms | ActiveRecord: 5.9ms)
>[----] I, [2018-09-13T10:11:16.999916 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 149ms (Views: 6.1ms | ActiveRecord: 20.1ms)
>[----] I, [2018-09-13T10:11:26.333660 #12616:3c442dc]  INFO -- : Started POST "/vm_cloud/x_button?pressed=instance_terminate" for 127.0.0.1 at 2018-09-13 10:11:26 -0400
>[----] I, [2018-09-13T10:11:26.337305 #12616:3c442dc]  INFO -- : Processing by VmCloudController#x_button as JS
>[----] I, [2018-09-13T10:11:26.337379 #12616:3c442dc]  INFO -- :   Parameters: {"miq_grid_checks"=>"41", "pressed"=>"instance_terminate"}
>[----] F, [2018-09-13T10:11:26.590728 #12616:3c442dc] FATAL -- : Error caught: [NoMethodError] undefined method `validate_vm_destroy' for #<ManageIQ::Providers::Openstack::CloudManager::Vm:0x0000000013bcc010>
>Did you mean?  validate_stop
>/opt/rh/cfme-gemset/gems/activemodel-5.0.7/lib/active_model/attribute_methods.rb:433:in `method_missing'
>/var/www/miq/vmdb/app/models/mixins/availability_mixin.rb:24:in `is_available?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:219:in `block in records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `each'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `find'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/helpers/application_helper.rb:215:in `records_support_feature?'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:665:in `generic_button_operation'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/ci_processing.rb:507:in `terminatevms'
>/opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/controllers/application_controller/explorer.rb:103:in `x_button'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:188:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:126:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:455:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/rescue.rb:20:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `block in instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/notifications.rb:164:in `instrument'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
>/opt/rh/cfme-gemset/gems/activerecord-5.0.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/abstract_controller/base.rb:126:in `process'
>/opt/rh/cfme-gemset/gems/actionview-5.0.7/lib/action_view/rendering.rb:30:in `process'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:190:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_controller/metal.rb:262:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:32:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:39:in `block in serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `each'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/journey/router.rb:26:in `serve'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/routing/route_set.rb:727:in `call'
>/opt/rh/cfme-gemset/bundler/gems/cfme-graphql-5f68621f2791/lib/manageiq/graphql/rest_api_proxy.rb:18: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.5/lib/rack/etag.rb:25:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/cookies.rb:613:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/callbacks.rb:90:in `run_callbacks'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:36:in `call_app'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/rack/logger.rb:26:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/request_id.rb:24:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
>/opt/rh/cfme-gemset/gems/activesupport-5.0.7/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
>/opt/rh/cfme-gemset/gems/actionpack-5.0.7/lib/action_dispatch/middleware/executor.rb:12:in `call'
>/opt/rh/cfme-gemset/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
>/opt/rh/cfme-gemset/gems/railties-5.0.7/lib/rails/engine.rb:522:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run'
>/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
>[----] I, [2018-09-13T10:11:26.592276 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exception_contents.html.haml (0.2ms)
>[----] I, [2018-09-13T10:11:26.592763 #12616:3c442dc]  INFO -- : Completed 200 OK in 255ms (Views: 1.2ms | ActiveRecord: 2.6ms)
>[----] I, [2018-09-13T10:11:30.750887 #12616:3c431ac]  INFO -- : Started POST "/vm_cloud/reload" for 127.0.0.1 at 2018-09-13 10:11:30 -0400
>[----] I, [2018-09-13T10:11:30.754147 #12616:3c431ac]  INFO -- : Processing by VmCloudController#reload as JS
>[----] I, [2018-09-13T10:11:30.791165 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:30.791500 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:30.792306 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.3ms)
>[----] I, [2018-09-13T10:11:30.792388 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.5ms)
>[----] I, [2018-09-13T10:11:30.793060 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.4ms)
>[----] I, [2018-09-13T10:11:30.801451 #12616:3c431ac]  INFO -- : Completed 200 OK in 47ms (Views: 6.2ms | ActiveRecord: 4.6ms)
>[----] I, [2018-09-13T10:11:31.244701 #12616:3c45b8c]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 10:11:31 -0400
>[----] I, [2018-09-13T10:11:31.249431 #12616:3c45b8c]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T10:11:31.249652 #12616:3c45b8c]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T10:11:31.412593 #12616:3c45b8c]  INFO -- : Completed 200 OK in 163ms (Views: 5.6ms | ActiveRecord: 22.7ms)
>[----] I, [2018-09-13T10:11:34.000554 #12616:3c49ca0]  INFO -- : Started GET "/vm_cloud/explorer" for 127.0.0.1 at 2018-09-13 10:11:34 -0400
>[----] I, [2018-09-13T10:11:34.004331 #12616:3c49ca0]  INFO -- : Processing by VmCloudController#explorer as HTML
>[----] I, [2018-09-13T10:11:34.062247 #12616:3c49ca0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application
>[----] I, [2018-09-13T10:11:34.063080 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_adv_searchbox.html.haml (0.5ms)
>[----] I, [2018-09-13T10:11:34.063793 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_input_filter.html.haml (0.5ms)
>[----] I, [2018-09-13T10:11:34.063874 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_quick_search.html.haml (0.7ms)
>[----] I, [2018-09-13T10:11:34.064301 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.064574 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_info_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.065302 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_gtl.html.haml (1.2ms)
>[----] I, [2018-09-13T10:11:34.065377 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_gtl.html.haml (1.4ms)
>[----] I, [2018-09-13T10:11:34.065438 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/vm_cloud/explorer.html.haml within layouts/application (3.1ms)
>[----] I, [2018-09-13T10:11:34.065612 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_doctype.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.066367 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/stylesheets/_template50.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.067374 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_i18n_js.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.068494 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_about_modal.html.haml (0.8ms)
>[----] I, [2018-09-13T10:11:34.072169 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_user_options.html.haml (2.9ms)
>[----] I, [2018-09-13T10:11:34.072423 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_notifications_drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:34.072571 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_toast_list.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.072708 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_spinner.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.072899 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_lightbox_panel.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.072968 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_header.html.haml (5.4ms)
>[----] I, [2018-09-13T10:11:34.084447 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_vertical_navbar.html.haml (11.2ms)
>[----] I, [2018-09-13T10:11:34.106654 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/angular/_toolbar.html.haml (21.9ms)
>[----] I, [2018-09-13T10:11:34.107504 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_x_form_buttons.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.108975 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/listnav/_explorer.html.haml (1.1ms)
>[----] I, [2018-09-13T10:11:34.109090 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_listnav.html.haml (1.3ms)
>[----] I, [2018-09-13T10:11:34.109261 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_content.html.haml (36.1ms)
>[----] I, [2018-09-13T10:11:34.112352 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_flash_msg.html.haml (0.0ms)
>[----] I, [2018-09-13T10:11:34.113937 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/exp_atom/_editor.html.haml (0.6ms)
>[----] I, [2018-09-13T10:11:34.114065 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_exp_editor.html.haml (1.8ms)
>[----] I, [2018-09-13T10:11:34.114127 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_body.html.haml (4.5ms)
>[----] I, [2018-09-13T10:11:34.116895 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search_footer.html.haml (2.6ms)
>[----] I, [2018-09-13T10:11:34.116980 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_adv_search.html.haml (7.5ms)
>[----] I, [2018-09-13T10:11:34.117067 #12616:3c49ca0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/layouts/_footer.html.haml (7.6ms)
>[----] I, [2018-09-13T10:11:34.119367 #12616:3c49ca0]  INFO -- : Completed 200 OK in 115ms (Views: 52.6ms | ActiveRecord: 9.6ms)
>[----] I, [2018-09-13T10:11:37.599424 #12616:3c3e5d0]  INFO -- : Started GET "/static/notification_drawer/notification-drawer.html" for 127.0.0.1 at 2018-09-13 10:11:37 -0400
>[----] I, [2018-09-13T10:11:37.602926 #12616:3c3e5d0]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:37.602995 #12616:3c3e5d0]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-drawer.html"}
>[----] I, [2018-09-13T10:11:37.603680 #12616:3c3e5d0]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml
>[----] I, [2018-09-13T10:11:37.603939 #12616:3c3e5d0]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-drawer.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:37.604161 #12616:3c3e5d0]  INFO -- : Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:37.848071 #12616:3c442dc]  INFO -- : Started GET "/static/notification_drawer/notification-heading.html" for 127.0.0.1 at 2018-09-13 10:11:37 -0400
>[----] I, [2018-09-13T10:11:37.851478 #12616:3c442dc]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:37.851558 #12616:3c442dc]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-heading.html"}
>[----] I, [2018-09-13T10:11:37.852470 #12616:3c431ac]  INFO -- : Started GET "/static/notification_drawer/notification-subheading.html" for 127.0.0.1 at 2018-09-13 10:11:37 -0400
>[----] I, [2018-09-13T10:11:37.854051 #12616:3c431ac]  INFO -- : Processing by StaticController#show as HTML
>[----] I, [2018-09-13T10:11:37.854137 #12616:3c431ac]  INFO -- :   Parameters: {"id"=>"notification_drawer/notification-subheading.html"}
>[----] I, [2018-09-13T10:11:37.854645 #12616:3c431ac]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml
>[----] I, [2018-09-13T10:11:37.855034 #12616:3c442dc]  INFO -- :   Rendering /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml
>[----] I, [2018-09-13T10:11:37.855348 #12616:3c431ac]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-subheading.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:37.855583 #12616:3c442dc]  INFO -- :   Rendered /opt/rh/cfme-gemset/bundler/gems/cfme-ui-classic-d119f9bc158f/app/views/static/notification_drawer/notification-heading.html.haml (0.1ms)
>[----] I, [2018-09-13T10:11:37.855867 #12616:3c431ac]  INFO -- : Completed 200 OK in 2ms (Views: 1.3ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:37.856142 #12616:3c442dc]  INFO -- : Completed 200 OK in 4ms (Views: 4.1ms | ActiveRecord: 0.0ms)
>[----] I, [2018-09-13T10:11:37.930064 #12616:3c45b8c]  INFO -- : Started POST "/vm_cloud/report_data" for 127.0.0.1 at 2018-09-13 10:11:37 -0400
>[----] I, [2018-09-13T10:11:37.934135 #12616:3c45b8c]  INFO -- : Processing by VmCloudController#report_data as HTML
>[----] I, [2018-09-13T10:11:37.934247 #12616:3c45b8c]  INFO -- :   Parameters: {"model_name"=>"ManageIQ::Providers::CloudManager::Vm", "model"=>"ManageIQ::Providers::CloudManager::Vm", "active_tree"=>"instances_filter_tree", "explorer"=>true, "additional_options"=>{"named_scope"=>nil, "gtl_dbname"=>nil, "model"=>"ManageIQ::Providers::CloudManager::Vm", "match_via_descendants"=>nil, "parent_id"=>nil, "parent_class_name"=>nil, "parent_method"=>nil, "association"=>nil, "view_suffix"=>nil, "row_button"=>nil, "menu_click"=>nil, "sb_controller"=>nil, "embedded"=>nil, "showlinks"=>nil, "policy_sim"=>nil, "in_a_form"=>nil, "lastaction"=>"show_list", "display"=>nil, "gtl_type"=>"grid", "supported_features_filter"=>nil, "clickable"=>nil, "no_checkboxes"=>nil}, "vm"=>{}}
>[----] I, [2018-09-13T10:11:38.078934 #12616:3c45b8c]  INFO -- : Completed 200 OK in 145ms (Views: 5.8ms | ActiveRecord: 19.7ms)
>[----] I, [2018-09-13T10:11:38.177548 #12627:f3497c]  INFO -- : Started GET "/api/notifications?expand=resources&attributes=details&sort_by=id&sort_order=desc&limit=100" for 127.0.0.1 at 2018-09-13 10:11:38 -0400
>[----] I, [2018-09-13T10:11:38.181489 #12627:f3497c]  INFO -- : Processing by Api::NotificationsController#index as JSON
>[----] I, [2018-09-13T10:11:38.181597 #12627:f3497c]  INFO -- :   Parameters: {"expand"=>"resources", "attributes"=>"details", "sort_by"=>"id", "sort_order"=>"desc", "limit"=>"100"}
>[----] I, [2018-09-13T10:11:38.214847 #12627:f3497c]  INFO -- : Completed 200 OK in 33ms (Views: 0.2ms | ActiveRecord: 5.8ms)
>[----] I, [2018-09-13T10:11:38.364469 #12627:f3497c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:11:38 -0400
>[----] I, [2018-09-13T10:11:38.368100 #12627:f3497c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:11:38.399273 #12627:f3497c]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 3.3ms)
>[----] I, [2018-09-13T10:12:38.384384 #12627:f3820c]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:12:38 -0400
>[----] I, [2018-09-13T10:12:38.387539 #12627:f3820c]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:12:38.415702 #12627:f3820c]  INFO -- : Completed 200 OK in 28ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:12:38.711169 #12627:f35dcc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:12:38 -0400
>[----] I, [2018-09-13T10:12:38.713933 #12627:f35dcc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:12:38.741010 #12627:f35dcc]  INFO -- : Completed 200 OK in 27ms (Views: 0.1ms | ActiveRecord: 2.9ms)
>[----] I, [2018-09-13T10:13:38.078610 #12627:f30ffc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:13:38 -0400
>[----] I, [2018-09-13T10:13:38.082226 #12627:f30ffc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:13:38.112862 #12627:f30ffc]  INFO -- : Completed 200 OK in 30ms (Views: 0.1ms | ActiveRecord: 3.8ms)
>[----] I, [2018-09-13T10:13:38.407138 #12627:f362cc]  INFO -- : Started GET "/api" for 127.0.0.1 at 2018-09-13 10:13:38 -0400
>[----] I, [2018-09-13T10:13:38.410515 #12627:f362cc]  INFO -- : Processing by Api::ApiController#index as JSON
>[----] I, [2018-09-13T10:13:38.441696 #12627:f362cc]  INFO -- : Completed 200 OK in 31ms (Views: 0.2ms | ActiveRecord: 3.1ms)
>

Actions: View

Attachments on bug 1628632: 1483083 | 1483084