Bug 1340416 - "Marshalling error for key 'MIQ:VMDB:..': can't dump hash with default proc" in production log when clicked on submit button of order service request.
Summary: "Marshalling error for key 'MIQ:VMDB:..': can't dump hash with default proc" ...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Automate
Version: 5.6.0
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: GA
: 5.6.0
Assignee: mkanoor
QA Contact: Aziza Karol
URL:
Whiteboard: error:service
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-05-27 11:04 UTC by Aziza Karol
Modified: 2016-07-13 16:45 UTC (History)
9 users (show)

Fixed In Version: 5.6.0.13
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-06-29 16:06:36 UTC
Category: ---
Cloudforms Team: ---
Target Upstream Version:


Attachments (Terms of Use)
snpshot (57.81 KB, image/png)
2016-05-27 11:04 UTC, Aziza Karol
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2016:1348 0 normal SHIPPED_LIVE CFME 5.6.0 bug fixes and enhancement update 2016-06-29 18:50:04 UTC

Description Aziza Karol 2016-05-27 11:04:05 UTC
Created attachment 1162420 [details]
snpshot

Description of problem:


Version-Release number of selected component (if applicable):
5.6.0.8-rc1.20160524155303_f2a5a50 

How reproducible:
100%

Steps to Reproduce:
1.create a catalog item type openstack 
2.Order the service.
3.

Actual results:
when clicked on submit button of order service request "ERROR -- : Marshalling error for key 'MIQ:VMDB:f477668300cbf7d01f5d9d20e888aef8': can't dump hash with default proc" displayed in Production log.

Expected results:
No error

Additional info:
production.log
[----] I, [2016-05-27T06:45:57.985721 #3066:af37f0]  INFO -- :   Parameters: {"ele1"=>"aziz", "id"=>"3"}
[----] I, [2016-05-27T06:45:58.281388 #3066:af37f0]  INFO -- : Completed 200 OK in 295ms (Views: 0.7ms | ActiveRecord: 0.0ms)
[----] I, [2016-05-27T06:46:00.583242 #3066:af1284]  INFO -- : Started POST "/catalog/dialog_form_button_pressed/3?button=submit" for 127.0.0.1 at 2016-05-27 06:46:00 -0400
[----] I, [2016-05-27T06:46:00.584880 #3066:af1284]  INFO -- : Processing by CatalogController#dialog_form_button_pressed as JS
[----] I, [2016-05-27T06:46:00.584980 #3066:af1284]  INFO -- :   Parameters: {"button"=>"submit", "id"=>"3"}
[----] I, [2016-05-27T06:46:01.415773 #3066:af1284]  INFO -- : Completed 200 OK in 831ms (Views: 1.1ms | ActiveRecord: 0.0ms)
[----] E, [2016-05-27T06:46:01.443618 #3066:af1284] ERROR -- : Marshalling error for key 'MIQ:VMDB:f477668300cbf7d01f5d9d20e888aef8': can't dump hash with default proc
[----] E, [2016-05-27T06:46:01.443706 #3066:af1284] ERROR -- : You are trying to cache a Ruby object which cannot be serialized to memcached.
[----] E, [2016-05-27T06:46:01.443764 #3066:af1284] ERROR -- : /opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/server.rb:414:in `dump'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/server.rb:414:in `serialize'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/server.rb:286:in `set'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/server.rb:67:in `request'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/options.rb:18:in `block in request'
	/opt/rh/rh-ruby22/root/usr/share/ruby/monitor.rb:211:in `mon_synchronize'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/options.rb:17:in `request'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/client.rb:362:in `perform'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/dalli/client.rb:126:in `set'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/rack/session/dalli.rb:61:in `block in set_session'
	/var/www/miq/vmdb/config/initializers/session_store.rb:35:in `block (3 levels) in with_lock'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/dependencies/interlock.rb:40:in `block in running'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/concurrency/share_lock.rb:128:in `sharing'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/dependencies/interlock.rb:39:in `running'
	/var/www/miq/vmdb/config/initializers/session_store.rb:34:in `block (2 levels) in with_lock'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/rack/session/dalli.rb:75:in `with_lock'
	/var/www/miq/vmdb/config/initializers/session_store.rb:33:in `block in with_lock'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/dependencies/interlock.rb:46:in `block in permit_concurrent_loads'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/concurrency/share_lock.rb:153:in `yield_shares'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/dependencies/interlock.rb:45:in `permit_concurrent_loads'
	/var/www/miq/vmdb/config/initializers/session_store.rb:32:in `with_lock'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/rack/session/dalli.rb:60:in `set_session'
	/opt/rh/cfme-gemset/gems/dalli-2.7.6/lib/rack/session/dalli.rb:28:in `write_session'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/session/abstract/id.rb:344:in `commit_session'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/session/abstract/id.rb:224:in `context'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/session/abstract/id.rb:216:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/cookies.rb:613:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/callbacks.rb:90:in `run_callbacks'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
	/opt/rh/cfme-gemset/gems/railties-5.0.0.rc1/lib/rails/rack/logger.rb:36:in `call_app'
	/opt/rh/cfme-gemset/gems/railties-5.0.0.rc1/lib/rails/rack/logger.rb:26:in `call'
	/opt/rh/cfme-gemset/gems/request_store-1.3.1/lib/request_store/middleware.rb:9:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/request_id.rb:24:in `call'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/method_override.rb:22:in `call'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/runtime.rb:22:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/activesupport/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
	/opt/rh/cfme-gemset/bundler/gems/rails-3f68565029fa/actionpack/lib/action_dispatch/middleware/executor.rb:12:in `call'
	/opt/rh/cfme-gemset/gems/rack-2.0.0.rc1/lib/rack/sendfile.rb:111:in `call'
	/opt/rh/cfme-gemset/gems/railties-5.0.0.rc1/lib/rails/engine.rb:522:in `call'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/configuration.rb:224:in `call'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:561:in `handle_request'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:406:in `process_client'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:271:in `block in run'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `call'
	/opt/rh/rh-ruby22/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `block in spawn_thread'
	/opt/rh/cfme-gemset/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
	/opt/rh/cfme-gemset/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
[----] I, [2016-05-27T06:46:01.747503 #3066:af0410]  INFO -- : Started GET "/miq_request/show_list?flash_msg=Order+Request+was+Submitted" for 127.0.0.1 at 2016-05-27 06:46:01 -0400
[----] I, [2016-05-27T06:46:01.749147 #3066:af0410]  INFO -- : Processing by MiqRequestController#show_list as HTML
[----] I, [2016-05-27T06:46:01.749221 #3066:af0410]  INFO -- :   Parameters: {"flash_msg"=>"Order Request was Submitted"}

Comment 2 Harpreet Kataria 2016-05-31 19:00:02 UTC
Aziza,

I was not able to recreate this issue, can you provide link to the appliance where i can see this happening.

Thanks,
~Harpreet

Comment 4 Harpreet Kataria 2016-06-20 17:16:53 UTC
I am seeing this issue while ordering some of the services, seems like blowing up on result = @edit[:wf].submit_request, https://github.com/ManageIQ/manageiq/blob/master/app/controllers/application_controller/dialog_runner.rb#L28 it looks like there is a default proc somewhere in @edit[:wf] object. Found this link http://stackoverflow.com/questions/17331768/rails-cant-dump-hash-with-default-proc-during-custom-validation that explains a bit about the same error. Perhaps someone from back-end team can look into it to see if something needs to be changed in code while initializing workflow object. 

Let me know if there is something we need to adjust in controller code to handle the issue.

Thanks,
~Harpreet

Comment 6 mkanoor 2016-06-21 00:52:36 UTC
We serialize the session object via Dali and there is the edit/wf/dialog 

object in the session object which cannot be serialized.

Should this @dialog object be stored in the session object or should we only have its id

It seems that the dialog instance variable in the :wf object is not dumpable, which causes this failure.
:wf=>#<ResourceActionWorkflow:0x0000000d466240.....

@dialog=#<Dialog id: 3, description: "service_provision_dialog", but
tons: "submit,cancel", created_at: "2016-06-20 11:05:08", updated_at: "2016-06-20 11:05:08", label: "service_
provision_dialog">>, :rec_id=>3, :key=>"dialog_edit__3", :explorer=>true, :target_id=>1, :target_kls=>"ServiceTemplate", :dialog_mode=>nil, :current=>{"ele"=>""}, :right_cell_text=>"Order Service \"vmware_provison\""},
 "view"=>#<MiqReport id: nil, name: "Catalog Items", title: "Catalog Items", rpt_group: nil, rpt_type: nil, p
riority: nil, db: "ServiceTemplate", cols: ["name", "description"], include: {"picture"=>{"columns"=>["id"]}, "tenant"=>{"columns"=>["name"]}}, col_order: ["name", "description", "tenant.name"], headers: ["Name", "Description", "Tenant"], conditions: nil, order: "Ascending", sortby: ["name"], group: "n", graph: nil, dims: nil
, created_on: nil, updated_on: nil, filename: nil, file_mtime: nil, categories: nil, timeline: nil, template_
type: nil, where_clause: nil, db_options: nil, generate_cols: nil, generate_rows: nil, col_formats: [], tz: n
il, time_profile_id: nil, display_filter: nil, col_options: nil, rpt_options: nil, miq_group_id: nil, user_id
: nil>, "changed"=>true}


It seems in the dialog object @dialog_field_hash is is causing Marshal.dump to fail.

Comment 7 Greg McCullough 2016-06-22 16:23:37 UTC
Madhu - My guess this is coming from some of the Default hashes used in the methods below.  I would suggest maybe Billy and Tina can work on refactoring this logic to not use default hash blocks.

Easy to find by just searching for "Hash.new" then look for a block to following it.
  Example: Hash.new { |h, k| h[k] = {} }

I found references in the following methods:
ManageIQ/Service/Provisioning/StateMachines/Methods/catalogiteminitialization.rb
ManageIQ/Service/Provisioning/StateMachines/Methods/dialog_parser.rb
ManageIQ/System/CommonMethods/QuotaMethods/requested.rb

RedHat/Service/Provisioning/StateMachines/ServiceProvisionRequestQuotaVerification/service_request_quota_validation.rb

Comment 10 Aziza Karol 2016-06-28 05:23:25 UTC
No Error when clicked on submit button of order service request.

Verified:5.6.0.13

Comment 12 errata-xmlrpc 2016-06-29 16:06:36 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1348


Note You need to log in before you can comment on or make changes to this bug.