Bug 1298844

Summary: Attempting to set a VMware Custom Attribute using vm.ems_custom_set gives a stack strace
Product: Red Hat CloudForms Management Engine Reporter: Peter McGowan <pmcgowan>
Component: ProvidersAssignee: Adam Grare <agrare>
Status: CLOSED ERRATA QA Contact: Milan Falešník <mfalesni>
Severity: medium Docs Contact:
Priority: high    
Version: 5.5.0CC: agrare, dajohnso, gblomqui, jfrey, jhardy, jprause, mkanoor, obarenbo, pmcgowan, tfitzger
Target Milestone: GA   
Target Release: 5.6.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: 5.6.0.0 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-06-29 15:30:39 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Peter McGowan 2016-01-15 09:12:42 UTC
Description of problem:
Using the VM object method 'ems_custom_set' to change an existing VMware custom attribute gives the following stack trace in evm.log:

[----] E, [2016-01-15T07:52:08.391727 #14634:ced998] ERROR -- : Q-task_id([resource_action_1000000000118]) MIQ(MiqQueue#deliver) Message id: [1000000116548], Error: [wrong number of arguments (0 for 1)]
[----] E, [2016-01-15T07:52:08.392441 #14634:ced998] ERROR -- : Q-task_id([resource_action_1000000000118]) [ArgumentError]: wrong number of arguments (0 for 1)  Method:[rescue in deliver]
[----] E, [2016-01-15T07:52:08.392828 #14634:ced998] ERROR -- : Q-task_id([resource_action_1000000000118]) (druby://127.0.0.1:58542) /var/www/miq/vmdb/gems/pending/VMwareWebService/MiqCustomFieldsManager.rb:40:in `key'
(druby://127.0.0.1:58542) /var/www/miq/vmdb/gems/pending/VMwareWebService/MiqCustomFieldsManager.rb:40:in `getFieldKey'
(druby://127.0.0.1:58542) /var/www/miq/vmdb/gems/pending/VMwareWebService/MiqVimVm.rb:1172:in `setCustomField'
(druby://127.0.0.1:58542) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block'
(druby://127.0.0.1:58542) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1584:in `perform'
(druby://127.0.0.1:58542) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop'
(druby://127.0.0.1:58542) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `loop'
(druby://127.0.0.1:58542) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `block in main_loop'
/var/www/miq/vmdb/app/models/manageiq/providers/vmware/infra_manager.rb:453:in `block in invoke_vim_ws'
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:16:in `block in with_provider_object'
/var/www/miq/vmdb/app/models/mixins/vim_connect_mixin.rb:36:in `with_provider_connection'
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:13:in `with_provider_object'
/var/www/miq/vmdb/app/models/manageiq/providers/vmware/infra_manager.rb:449:in `invoke_vim_ws'
/var/www/miq/vmdb/app/models/manageiq/providers/vmware/infra_manager.rb:428:in `vm_set_custom_field'
/var/www/miq/vmdb/app/models/vm_or_template.rb:328:in `run_command_via_parent'
/var/www/miq/vmdb/app/models/vm_or_template.rb:302:in `raw_set_custom_field'
/var/www/miq/vmdb/app/models/vm_or_template.rb:306:in `set_custom_field'
/var/www/miq/vmdb/app/models/miq_queue.rb:345:in `block in deliver'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:89:in `block in timeout'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `block in catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:104:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:341:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:106:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:134:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:151:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:145:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:145:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:334:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:128:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:29:in `start_worker'
/var/www/miq/vmdb/lib/workers/bin/worker.rb:2:in `<top (required)>'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/runner.rb:60:in `load'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/runner.rb:60:in `<top (required)>'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/commands_tasks.rb:123:in `require'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/commands_tasks.rb:123:in `require_command!'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/commands_tasks.rb:90:in `runner'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
/opt/rh/cfme-gemset/gems/railties-4.2.5/lib/rails/commands.rb:17:in `<top (required)>'
/var/www/miq/vmdb/bin/rails:4:in `require'

Changing line 40 in MiqCustomFieldsManager.rb from fsa.first.key to fsa.first['key'] seems to fix the problem.

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

How reproducible:
Every time

Steps to Reproduce:
1. Find a VM that has an existing VMware custom attribute (listed as a VC Custom Attribute in the WebUI)
2. Attempt to change this using the 'ems_custom_set' method on the VM object.
3.

Actual results:
Stack trace in evm.log

Expected results:
The custom attribute should be changed

Additional info:

Comment 2 Greg McCullough 2016-01-15 14:22:49 UTC
Peter - What version of vSphere were you running against?

Comment 3 Peter McGowan 2016-01-17 13:18:54 UTC
It's vSphere 5.1

Comment 4 Peter McGowan 2016-01-18 13:12:28 UTC
That last comment was incorrect, it's vSphere 5.5 u2. CloudForms reports ext_management_system.api_version as 5.5

Comment 5 Greg McCullough 2016-01-18 17:06:50 UTC
Reassigning this issue to the provider group.  The call initiates from automate to set an attribute in VMware, but the failure is in the VMwareWebService/MiqCustomFieldsManager.rb code.

Comment 7 CFME Bot 2016-01-21 15:45:57 UTC
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/418969bd7f6a5a096fc7003e1d52c95783502eef

commit 418969bd7f6a5a096fc7003e1d52c95783502eef
Author:     Adam Grare <agrare>
AuthorDate: Mon Jan 18 14:46:22 2016 -0500
Commit:     Adam Grare <agrare>
CommitDate: Mon Jan 18 15:01:33 2016 -0500

    Disable inheritance of method :key in VimHash
    
    The inherited Hash :key method is clashing with the behavior of
    VimHash to access a key using :method_missing and sym.to_s.
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1298844

 gems/pending/VMwareWebService/VimTypes.rb | 1 +
 1 file changed, 1 insertion(+)

Comment 8 Milan Falešník 2016-05-27 14:27:56 UTC
Verified in 5.6.0.8.

I have deployed a vSphere VM, set a custom VC custom attribute on it using vmware client. Then I opened rails console, created $evm and retireved the VM.

the ems_custom_set was setting the value properly as I was watching the data in the vmware client.

Comment 10 errata-xmlrpc 2016-06-29 15:30:39 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