Bug 1247664 - vm.create_snapshot fails for vmware vm Handsoap::Fault
vm.create_snapshot fails for vmware vm Handsoap::Fault
Status: CLOSED ERRATA
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Automate (Show other bugs)
5.4.0
All All
medium Severity medium
: GA
: 5.5.0
Assigned To: mkanoor
Pete Savage
: ZStream
Depends On:
Blocks: 1252039
  Show dependency treegraph
 
Reported: 2015-07-28 10:44 EDT by Josh Carter
Modified: 2017-05-19 08:59 EDT (History)
7 users (show)

See Also:
Fixed In Version: 5.5.0.1
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1252039 (view as bug list)
Environment:
Last Closed: 2015-12-08 08:24:19 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
mfalesni: automate_bug-


Attachments (Terms of Use)

  None (edit)
Description Josh Carter 2015-07-28 10:44:49 EDT
Description of problem:

Calling vm.create_snapshot fails for a vmware vm with the following error. 

[----] I, [2015-07-28T09:57:12.674530 #3602:c21e9c]  INFO -- : MIQ(EmsVmware.invoke_vim_ws) EMS: [vmware] VmVmware: id [12000000000117], name [cbts-db], ems_ref [vm-360] Invoking [createSnapshot]...
[----] I, [2015-07-28T09:57:12.725973 #50176:4327874]  INFO -- : Snapshot create pre-check OK.  Datastore <datastore1> has enough free space.  Space Free:<90267713536>  Required:<42949672960>  Disk Percentage Used:<100>
[----] E, [2015-07-28T09:57:12.735942 #3602:c21e9c] ERROR -- : MIQ(MiqQueue.deliver)    Message id: [12000001358639], Error: [Handsoap::Fault { :code => 'ServerFaultCode', :reason => '
Cannot parse "" as a bool value

while parsing serialized value of type boolean
at line 9, column 6

while parsing call information for method CreateSnapshot_Task
at line 5, column 4

while parsing SOAP body
at line 4, column 2

while parsing SOAP envelope
at line 2, column 0

while parsing HTTP request for method createSnapshot
on object of type vim.VirtualMachine
at line 1, column 0' }]
[----] E, [2015-07-28T09:57:12.736271 #3602:c21e9c] ERROR -- : [Handsoap::Fault]: Handsoap::Fault { :code => 'ServerFaultCode', :reason => '
Cannot parse "" as a bool value

while parsing serialized value of type boolean
at line 9, column 6

while parsing call information for method CreateSnapshot_Task
at line 5, column 4

while parsing SOAP body
at line 4, column 2

while parsing SOAP envelope
at line 2, column 0

while parsing HTTP request for method createSnapshot
on object of type vim.VirtualMachine
at line 1, column 0' }  Method:[rescue in deliver]
[----] E, [2015-07-28T09:57:12.736478 #3602:c21e9c] ERROR -- : (druby://127.0.0.1:34440) /opt/rh/cfme-gemset/bundler/gems/handsoap-daec1277652f/lib/handsoap/service.rb:198:in `on_fault'
(druby://127.0.0.1:34440) /opt/rh/cfme-gemset/bundler/gems/handsoap-daec1277652f/lib/handsoap/service.rb:288:in `dispatch'
(druby://127.0.0.1:34440) /opt/rh/cfme-gemset/bundler/gems/handsoap-daec1277652f/lib/handsoap/service.rb:192:in `invoke'
(druby://127.0.0.1:34440) /var/www/miq/lib/VMwareWebService/VimService.rb:264:in `createSnapshot_Task'
(druby://127.0.0.1:34440) /var/www/miq/lib/VMwareWebService/MiqVimVm.rb:375:in `createSnapshot'
(druby://127.0.0.1:34440) /opt/rh/ruby200/root/usr/share/ruby/drb/drb.rb:1588:in `perform_without_block'
(druby://127.0.0.1:34440) /opt/rh/ruby200/root/usr/share/ruby/drb/drb.rb:1548:in `perform'
(druby://127.0.0.1:34440) /opt/rh/ruby200/root/usr/share/ruby/drb/drb.rb:1626:in `block (2 levels) in main_loop'
(druby://127.0.0.1:34440) /opt/rh/ruby200/root/usr/share/ruby/drb/drb.rb:1622:in `loop'
(druby://127.0.0.1:34440) /opt/rh/ruby200/root/usr/share/ruby/drb/drb.rb:1622:in `block in main_loop'
(druby://127.0.0.1:34440) /var/www/miq/vmdb/lib/extensions/ar_thread.rb:22:in `block in start_with_release'
/var/www/miq/vmdb/app/models/ems_vmware.rb:410: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:39: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/ems_vmware.rb:406:in `invoke_vim_ws'
/var/www/miq/vmdb/app/models/ems_vmware.rb:303:in `vm_create_snapshot'
/var/www/miq/vmdb/app/models/vm_or_template.rb:336:in `run_command_via_parent'
/var/www/miq/vmdb/app/models/vm_or_template/operations/snapshot.rb:32:in `raw_create_snapshot'
/var/www/miq/vmdb/app/models/vm_or_template/operations/snapshot.rb:36:in `create_snapshot'
/var/www/miq/vmdb/app/models/miq_queue.rb:356:in `block in deliver'
/opt/rh/ruby200/root/usr/share/ruby/timeout.rb:66:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:352:in `deliver'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:107:in `deliver_queue_message'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:135:in `deliver_message'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:152:in `block in do_work'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `loop'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `do_work'
/var/www/miq/vmdb/lib/workers/worker_base.rb:323:in `block in do_work_loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `do_work_loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:141:in `run'
/var/www/miq/vmdb/lib/workers/worker_base.rb:122:in `start'
/var/www/miq/vmdb/lib/workers/worker_base.rb:23:in `start_worker'
/var/www/miq/vmdb/lib/workers/bin/worker.rb:3:in `<top (required)>'
/opt/rh/cfme-gemset/bundler/gems/rails-4842a8377644/railties/lib/rails/commands/runner.rb:52:in `eval'
/opt/rh/cfme-gemset/bundler/gems/rails-4842a8377644/railties/lib/rails/commands/runner.rb:52:in `<top (required)>'
/opt/rh/cfme-gemset/bundler/gems/rails-4842a8377644/railties/lib/rails/commands.rb:64:in `require'
/opt/rh/cfme-gemset/bundler/gems/rails-4842a8377644/railties/lib/rails/commands.rb:64:in `<top (required)>'
script/rails:6:in `require'
script/rails:6:in `<main>'
[----] I, [2015-07-28T09:57:12.736974 #3602:c21e9c]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [12000001358639], State: [error], Delivered in [0.292406502] seconds

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


How reproducible:
very

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

vm hosted on vcenter 5.1
Comment 1 Josh Carter 2015-07-28 10:45:35 EDT
Method used 


###################################
#
# EVM Automate Method: createSnapshot
#
# Notes: This method creates a snapshot on a given VM via web service API
#
# Inputs: GUID, [snap_name, snap_description]
#
###################################
begin
  @method = 'createSnapshot'
  $evm.log("info", "#{@method} - EVM Automate Method Started")

  # Turn of verbose logging
  @debug = true

  ####################
  #
  # Method: createSnapshot
  #
  ####################
  def createSnapshot(vm, snap_name, snap_desc=snap_name)
    $evm.log("info","#{@method} - VM:<#{vm.name}> Creating Snapshot:<#{snap_name}> Description:<#{snap_desc}>")
    vm.create_snapshot(snap_name, snap_desc)
  end

  #$evm.root.attributes.sort.each { |k, v| $evm.log("info", "\t#{k}: #{v}")} if @debug

  # Get VM object from the root object
  vm = $evm.root['vm']

  # If VM is nil then assume web service call and look for GUID from root object
  if vm.nil?
    $evm.log("info","Execution of method:<#{@method}> via API detected") if @debug
    # Get GUID from foot object
    guid = $evm.root['guid']

    # Lookup VM by GUID
    vm = $evm.vmdb('vm').find_by_guid(guid)
    # Bail out if VM is not found
    raise "#{@method} - VM with GUID:<#{guid}> not found" if vm.nil?
    $evm.log("info","#{@method} - Assigning VM:<#{vm.name}> to root object") if @debug
    $evm.root['vm'] = vm
    $evm.log("info","#{@method} - Found VM:<#{vm.name}> via GUID:<#{guid}>") if @debug
  end

  snap_name = $evm.root['snap_name'] || "Snapshot #{Time.now}"
  snap_desc = $evm.root['snap_desc'] || "Snapshot:<#{snap_name}> for #{vm.name}"

  # Call createSnapshot method
  createSnapshot(vm, snap_name, snap_desc)

  #
  # Exit method
  #
  $evm.log("info", "#{@method} - EVM Automate Method Ended")
  exit MIQ_OK


  #
  # Set Ruby rescue behavior
  #
rescue => err
  $evm.log("error", "#{@method} - [#{err}]\n#{err.backtrace.join("\n")}")
  exit MIQ_ABORT
end
Comment 3 Josh Carter 2015-07-28 11:06:10 EDT
The UI snapshot create works as expected.  

[----] I, [2015-07-28T11:02:07.094512 #3605:b93ea8]  INFO -- : MIQ(EmsVmware.invoke_vim_ws) EMS: [vmware] VmVmware: id [1200000000011
7], name [cbts-db], ems_ref [vm-360] Invoking [createSnapshot]...
[----] I, [2015-07-28T11:02:10.472216 #3605:b93ea8]  INFO -- : MIQ(EmsVmware.invoke_vim_ws) EMS: [vmware] VmVmware: id [1200000000011
7], name [cbts-db], ems_ref [vm-360] Returned with result [snapshot-445]
[----] I, [2015-07-28T11:02:10.493691 #3605:b93ea8]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [12000001359246], State: [ok], De
livered in [3.629023822] seconds
[----] I, [2015-07-28T11:02:10.497968 #3605:b93ea8]  INFO -- : MIQ(MiqQueue.m_callback) Message id: [12000001359246], Invoking Callba
ck with args: ["Finished", "ok", "Message delivered successfully", "\"snapshot-445\""]
Comment 5 CFME Bot 2015-08-10 10:03:22 EDT
New commit detected on manageiq/master:
https://github.com/ManageIQ/manageiq/commit/978c1120217541849420e930c8d2743b00b6780a

commit 978c1120217541849420e930c8d2743b00b6780a
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 13:58:13 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Wed Aug 5 13:58:13 2015 -0400

    Moved snapshot code to vm ware specific class
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 ...ce_manageiq-providers-vmware-infra_manager-vm.rb | 21 +++++++++++++++++++++
 .../service_models/miq_ae_service_vm_or_template.rb | 21 ---------------------
 2 files changed, 21 insertions(+), 21 deletions(-)
Comment 6 CFME Bot 2015-08-10 10:03:27 EDT
New commit detected on manageiq/master:
https://github.com/ManageIQ/manageiq/commit/5df0c2052710f4ff8b4941c0f902397680b86a72

commit 5df0c2052710f4ff8b4941c0f902397680b86a72
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 16:29:36 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Wed Aug 5 16:29:36 2015 -0400

    Expose the memory parameter to automate methods
    
    Sets the default memory value to be false unless specified
    by the automate method.
    Added specs to validate the snapshot parameters
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 ...e_manageiq-providers-vmware-infra_manager-vm.rb |  4 ++--
 ...ageiq-providers-vmware-infra_manager-vm_spec.rb | 23 ++++++++++++++++++++++
 2 files changed, 25 insertions(+), 2 deletions(-)
Comment 7 CFME Bot 2015-08-10 10:03:31 EDT
New commit detected on manageiq/master:
https://github.com/ManageIQ/manageiq/commit/6dac115d868920800e255ea04ff78dabc9597977

commit 6dac115d868920800e255ea04ff78dabc9597977
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 17:10:03 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Wed Aug 5 17:10:03 2015 -0400

    Fixed rubocop warnings
    
    Rubocop cleanup
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 .../miq_ae_service_manageiq-providers-vmware-infra_manager-vm.rb  | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)
Comment 8 CFME Bot 2015-08-10 15:01:49 EDT
New commit detected on cfme/5.4.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=2ad9c1ca52131a164cecee244dc387ec566bd9c4

commit 2ad9c1ca52131a164cecee244dc387ec566bd9c4
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 13:58:13 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Mon Aug 10 10:51:46 2015 -0400

    Moved snapshot code to vm ware specific class
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 .../service_models/miq_ae_service_vm_or_template.rb | 21 ---------------------
 .../service_models/miq_ae_service_vm_vmware.rb      | 21 +++++++++++++++++++++
 2 files changed, 21 insertions(+), 21 deletions(-)
Comment 9 CFME Bot 2015-08-10 15:01:53 EDT
New commit detected on cfme/5.4.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=98f3f59ad211dae011c4f8379ac6ab2fa8353648

commit 98f3f59ad211dae011c4f8379ac6ab2fa8353648
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 16:29:36 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Mon Aug 10 10:51:46 2015 -0400

    Expose the memory parameter to automate methods
    
    Sets the default memory value to be false unless specified
    by the automate method.
    Added specs to validate the snapshot parameters
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 .../service_models/miq_ae_service_vm_vmware.rb     |  4 ++--
 .../miq_ae_service_vm_vmware_spec.rb               | 23 ++++++++++++++++++++++
 2 files changed, 25 insertions(+), 2 deletions(-)
Comment 10 CFME Bot 2015-08-10 15:01:56 EDT
New commit detected on cfme/5.4.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=bf6a47b0d388f29c815967cbd5cfa3785b8a9025

commit bf6a47b0d388f29c815967cbd5cfa3785b8a9025
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Wed Aug 5 17:10:03 2015 -0400
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Mon Aug 10 10:51:47 2015 -0400

    Fixed rubocop warnings
    
    Rubocop cleanup
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1247664

 .../service_models/miq_ae_service_vm_vmware.rb                    | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)
Comment 11 Pete Savage 2015-10-27 05:46:24 EDT
Verified in 5.5.0.7
Comment 13 errata-xmlrpc 2015-12-08 08:24:19 EST
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/RHSA-2015:2551

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