Description of problem: ============================== simple template clone provision failing with rhev providers, all versions, here is a snippet of the stack trace... see below for more of the log/trace [----] E, [2015-09-22T22:11:04.685091 #2553:377990] ERROR -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#provision_error) [[ArgumentError]: wrong number of arguments (2 for 0)] encountered during phase [start_clone_task] [----] E, [2015-09-22T22:11:04.685260 #2553:377990] ERROR -- : Q-task_id([miq_provision_1]) /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/abstract_response.rb:71:in `return!' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/service.rb:207:in `block in resource_verb' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `call' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `process_result' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:504:in `block in transmit' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:853:in `start' Version-Release number of selected component (if applicable): ============================================= 5.5.0.1 How reproducible: ======================= 100% Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info: ==================================== [----] I, [2015-09-22T22:11:00.909821 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <run_provision> [----] I, [2015-09-22T22:11:01.034495 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <create_destination> [----] I, [2015-09-22T22:11:01.117981 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <determine_placement> [----] I, [2015-09-22T22:11:01.210672 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#placement) Using Cluster Id: [2], Name: [iscsi] [----] I, [2015-09-22T22:11:01.210944 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#placement) Using Host Id: [2], Name: [qeblade29] [----] I, [2015-09-22T22:11:01.211087 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#placement) Using Storage Id: [2], Name: [rhevm34_data] [----] I, [2015-09-22T22:11:01.211285 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <prepare_provision> [----] I, [2015-09-22T22:11:01.451975 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#prepare_provision) Default Clone Options: [:name](String) = "test_dajo_prov09234" [----] I, [2015-09-22T22:11:01.452165 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#prepare_provision) Default Clone Options: [:cluster](String) = "/api/clusters/7944d769-94d2-4aca-becd-9748ccc28cd4" [----] I, [2015-09-22T22:11:01.452242 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#prepare_provision) Default Clone Options: [:clone_type](Symbol) = :full [----] I, [2015-09-22T22:11:01.452443 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#prepare_provision) Default Clone Options: [:sparse](NilClass) = nil [----] I, [2015-09-22T22:11:01.452518 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#prepare_provision) Default Clone Options: [:storage](String) = "/api/storagedomains/77295070-22e4-4ebb-ad24-6d2f69921517" [----] I, [2015-09-22T22:11:01.452856 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <start_clone_task> [----] I, [2015-09-22T22:11:01.700440 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Provisioning [rhel65] to [test_dajo_prov09234] [----] I, [2015-09-22T22:11:01.700639 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Source Template: [rhel65] [----] I, [2015-09-22T22:11:01.700708 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Clone Type: [full] [----] I, [2015-09-22T22:11:01.700767 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Destination VM Name: [test_dajo_prov09234] [----] I, [2015-09-22T22:11:01.700892 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Destination Cluster: [iscsi (/api/clusters/7944d769-94d2-4aca-becd-9748ccc28cd4)] [----] I, [2015-09-22T22:11:01.701010 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Destination Datastore: [rhevm34_data (/api/storagedomains/77295070-22e4-4ebb-ad24-6d2f69921517)] [----] I, [2015-09-22T22:11:01.701160 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Clone Options: [:name](String) = "test_dajo_prov09234" [----] I, [2015-09-22T22:11:01.701229 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Clone Options: [:cluster](String) = "/api/clusters/7944d769-94d2-4aca-becd-9748ccc28cd4" [----] I, [2015-09-22T22:11:01.701295 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Clone Options: [:clone_type](Symbol) = :full [----] I, [2015-09-22T22:11:01.701474 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Clone Options: [:storage](String) = "/api/storagedomains/77295070-22e4-4ebb-ad24-6d2f69921517" [----] I, [2015-09-22T22:11:01.704500 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:initial_pass](TrueClass) = true [----] I, [2015-09-22T22:11:01.704636 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_vm_id][0](Fixnum) = 58 [----] I, [2015-09-22T22:11:01.704714 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_vm_id][1](String) = "rhel65" [----] I, [2015-09-22T22:11:01.704802 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:miq_request_dialog_name](String) = "miq_provision_redhat_dialogs_template" [----] I, [2015-09-22T22:11:01.704982 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:current_tab_key](Symbol) = :customize [----] I, [2015-09-22T22:11:01.705065 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_phone](NilClass) = nil [----] I, [2015-09-22T22:11:01.705139 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_country](NilClass) = nil [----] I, [2015-09-22T22:11:01.705208 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_phone_mobile](NilClass) = nil [----] I, [2015-09-22T22:11:01.705271 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_title](NilClass) = nil [----] I, [2015-09-22T22:11:01.705334 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_first_name](String) = "dave" [----] I, [2015-09-22T22:11:01.705419 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_manager](NilClass) = nil [----] I, [2015-09-22T22:11:01.705483 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_address](NilClass) = nil [----] I, [2015-09-22T22:11:01.705544 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_company](NilClass) = nil [----] I, [2015-09-22T22:11:01.705616 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_last_name](String) = "dave" [----] I, [2015-09-22T22:11:01.705687 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_manager_mail](NilClass) = nil [----] I, [2015-09-22T22:11:01.705841 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_city](NilClass) = nil [----] I, [2015-09-22T22:11:01.705910 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_department](NilClass) = nil [----] I, [2015-09-22T22:11:01.705972 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_load_ldap](NilClass) = nil [----] I, [2015-09-22T22:11:01.706033 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_manager_phone](NilClass) = nil [----] I, [2015-09-22T22:11:01.706101 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_state](NilClass) = nil [----] I, [2015-09-22T22:11:01.706167 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_office](NilClass) = nil [----] I, [2015-09-22T22:11:01.706236 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_zip](NilClass) = nil [----] I, [2015-09-22T22:11:01.706300 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:owner_email](String) = "dave" [----] I, [2015-09-22T22:11:01.706361 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:request_notes](NilClass) = nil [----] I, [2015-09-22T22:11:01.706449 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_tags](Array) = EMPTY [----] I, [2015-09-22T22:11:01.706516 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:customization_template_script](NilClass) = nil [----] I, [2015-09-22T22:11:01.706660 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dns_servers](NilClass) = nil [----] I, [2015-09-22T22:11:01.706730 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dns_suffixes](NilClass) = nil [----] I, [2015-09-22T22:11:01.706798 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:root_password](NilClass) = <PROTECTED> [----] I, [2015-09-22T22:11:01.706889 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:addr_mode][0](String) = "static" [----] I, [2015-09-22T22:11:01.706954 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:addr_mode][1](String) = "Static" [----] I, [2015-09-22T22:11:01.707016 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:gateway](NilClass) = nil [----] I, [2015-09-22T22:11:01.707076 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:hostname](NilClass) = nil [----] I, [2015-09-22T22:11:01.707143 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:ip_addr](NilClass) = nil [----] I, [2015-09-22T22:11:01.707213 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:subnet_mask](NilClass) = nil [----] I, [2015-09-22T22:11:01.707291 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_cluster_name][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.707458 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_cluster_name][1](String) = "iscsi" [----] I, [2015-09-22T22:11:01.707536 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:cluster_filter][0](NilClass) = nil [----] I, [2015-09-22T22:11:01.707609 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:cluster_filter][1](NilClass) = nil [----] I, [2015-09-22T22:11:01.707695 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_auto][0](FalseClass) = false [----] I, [2015-09-22T22:11:01.707777 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_auto][1](Fixnum) = 0 [----] I, [2015-09-22T22:11:01.707870 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_dc_name][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.707938 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_dc_name][1](String) = "Default" [----] I, [2015-09-22T22:11:01.708019 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_host_name][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.708089 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_host_name][1](String) = "qeblade29" [----] I, [2015-09-22T22:11:01.708253 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_ds_name][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.708319 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:placement_ds_name][1](String) = "rhevm34_data" [----] I, [2015-09-22T22:11:01.708415 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:number_of_vms][0](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.708487 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:number_of_vms][1](String) = "1" [----] I, [2015-09-22T22:11:01.708553 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_description](NilClass) = nil [----] I, [2015-09-22T22:11:01.708625 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_prefix](NilClass) = nil [----] I, [2015-09-22T22:11:01.708702 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:provision_type][0](String) = "native_clone" [----] I, [2015-09-22T22:11:01.708769 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:provision_type][1](String) = "Native Clone" [----] I, [2015-09-22T22:11:01.708940 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:linked_clone][0](NilClass) = nil [----] I, [2015-09-22T22:11:01.709014 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:linked_clone][1](NilClass) = nil [----] I, [2015-09-22T22:11:01.709079 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_name](String) = "test_dajo_prov09234" [----] I, [2015-09-22T22:11:01.709156 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:pxe_server_id][0](NilClass) = nil [----] I, [2015-09-22T22:11:01.709224 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:pxe_server_id][1](NilClass) = nil [----] I, [2015-09-22T22:11:01.709304 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:schedule_type][0](String) = "immediately" [----] I, [2015-09-22T22:11:01.709392 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:schedule_type][1](String) = "Immediately on Approval" [----] I, [2015-09-22T22:11:01.709479 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_auto_start][0](TrueClass) = true [----] I, [2015-09-22T22:11:01.709547 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_auto_start][1](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.709630 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:schedule_time](Time) = 2015-09-24 00:00:00 UTC [----] I, [2015-09-22T22:11:01.709760 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:retirement][0](Fixnum) = 0 [----] I, [2015-09-22T22:11:01.709833 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:retirement][1](String) = "Indefinite" [----] I, [2015-09-22T22:11:01.709921 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:retirement_warn][0](Fixnum) = 604800 [----] I, [2015-09-22T22:11:01.709989 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:retirement_warn][1](String) = "1 Week" [----] I, [2015-09-22T22:11:01.710068 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:stateless][0](FalseClass) = false [----] I, [2015-09-22T22:11:01.710134 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:stateless][1](Fixnum) = 0 [----] I, [2015-09-22T22:11:01.710216 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vlan][0](String) = "rhevm" [----] I, [2015-09-22T22:11:01.710285 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vlan][1](String) = "rhevm" [----] I, [2015-09-22T22:11:01.710405 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:mac_address](NilClass) = nil [----] I, [2015-09-22T22:11:01.710489 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:disk_format][0](String) = "default" [----] I, [2015-09-22T22:11:01.710555 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:disk_format][1](String) = "Default" [----] I, [2015-09-22T22:11:01.710651 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:number_of_sockets][0](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.710720 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:number_of_sockets][1](String) = "1" [----] I, [2015-09-22T22:11:01.710804 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:cores_per_socket][0](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.710881 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:cores_per_socket][1](String) = "1" [----] I, [2015-09-22T22:11:01.710968 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_memory][0](String) = "2048" [----] I, [2015-09-22T22:11:01.711075 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_memory][1](String) = "2048" [----] I, [2015-09-22T22:11:01.711140 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:memory_reserve](NilClass) = nil [----] I, [2015-09-22T22:11:01.711222 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:network_adapters][0](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.711296 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:network_adapters][1](String) = "1" [----] I, [2015-09-22T22:11:01.711361 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:start_date](String) = "9/24/2015" [----] I, [2015-09-22T22:11:01.711449 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:start_hour](String) = "00" [----] I, [2015-09-22T22:11:01.711512 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:start_min](String) = "00" [----] I, [2015-09-22T22:11:01.711571 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_vm_nics](Array) = EMPTY [----] I, [2015-09-22T22:11:01.711642 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_vm_lans](Array) = EMPTY [----] I, [2015-09-22T22:11:01.711760 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:customize_enabled][0](String) = "enabled" [----] I, [2015-09-22T22:11:01.711840 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_ems_id][0](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.711911 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:src_ems_id][1](String) = "rhevm34" [----] I, [2015-09-22T22:11:01.711984 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:delivered_on](Time) = 2015-09-23 02:10:24 UTC [----] I, [2015-09-22T22:11:01.712056 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:pass](Fixnum) = 1 [----] I, [2015-09-22T22:11:01.712124 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dns_domain](NilClass) = nil [----] I, [2015-09-22T22:11:01.712187 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_target_name](String) = "test_dajo_prov09234" [----] I, [2015-09-22T22:11:01.712254 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_target_hostname](String) = "test-dajo-prov09234" [----] I, [2015-09-22T22:11:01.712332 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:vm_notes](String) = "Owner: dave dave\nEmail: dave\nSource Template: rhel65" [----] I, [2015-09-22T22:11:01.712495 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_cluster][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.712565 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_cluster][1](String) = "iscsi" [----] I, [2015-09-22T22:11:01.712655 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_host][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.712722 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_host][1](String) = "qeblade29" [----] I, [2015-09-22T22:11:01.712801 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_storage][0](Fixnum) = 2 [----] I, [2015-09-22T22:11:01.712867 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#log_clone_options) Prov Options: [:dest_storage][1](String) = "rhevm34_data" [----] I, [2015-09-22T22:11:01.713259 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager#with_provider_connection) Connecting through ManageIQ::Providers::Redhat::InfraManager: [rhevm34] [----] E, [2015-09-22T22:11:04.578567 #2553:377990] ERROR -- : Q-task_id([miq_provision_1]) <RHEVM> Ovirt::Service#resource_post: class = ArgumentError, message=wrong number of arguments (2 for 0), URI=https://10.16.4.106:443/api/vms [----] I, [2015-09-22T22:11:04.579388 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <provision_error> [----] E, [2015-09-22T22:11:04.685091 #2553:377990] ERROR -- : Q-task_id([miq_provision_1]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#provision_error) [[ArgumentError]: wrong number of arguments (2 for 0)] encountered during phase [start_clone_task] [----] E, [2015-09-22T22:11:04.685260 #2553:377990] ERROR -- : Q-task_id([miq_provision_1]) /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/abstract_response.rb:71:in `return!' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/service.rb:207:in `block in resource_verb' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `call' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:592:in `process_result' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:504:in `block in transmit' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:853:in `start' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:494:in `transmit' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:202:in `execute' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/request.rb:52:in `execute' /opt/rh/cfme-gemset/gems/rest-client-2.0.0.rc1/lib/restclient/resource.rb:67:in `post' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/service.rb:200:in `resource_verb' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/service.rb:181:in `resource_post' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/template.rb:130:in `clone_to_vm' /opt/rh/cfme-gemset/gems/ovirt-0.6.0/lib/ovirt/template.rb:85:in `create_vm' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/provision/cloning.rb:61:in `block in start_clone' /var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:16:in `block in with_provider_object' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager.rb:92: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/redhat/infra_manager/provision/cloning.rb:60:in `start_clone' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:16:in `start_clone_task' /var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal' /var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:17:in `prepare_provision' /var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:9:in `determine_placement' /var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal' /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:3:in `create_destination' /var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal' /var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:4:in `run_provision' /var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal' /var/www/miq/vmdb/app/models/miq_provision_task.rb:15:in `do_request' /var/www/miq/vmdb/app/models/miq_request_task.rb:178:in `execute' /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/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:329:in `block in do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:326:in `loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:326:in `do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:146:in `run' /var/www/miq/vmdb/lib/workers/worker_base.rb:127:in `start' /var/www/miq/vmdb/lib/workers/worker_base.rb:24:in `start_worker' /var/www/miq/vmdb/lib/workers/bin/worker.rb:3:in `<top (required)>' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/runner.rb:60:in `load' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/runner.rb:60:in `<top (required)>' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:123:in `require' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:123:in `require_command!' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:90:in `runner' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:39:in `run_command!' /opt/rh/cfme-gemset/gems/railties-4.2.4/lib/rails/commands.rb:17:in `<top (required)>' /var/www/miq/vmdb/bin/rails:4:in `require' /var/www/miq/vmdb/bin/rails:4:in `<main>' [----] I, [2015-09-22T22:11:04.994031 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) Starting Phase <finish> [----] I, [2015-09-22T22:11:05.086071 #2553:377990] INFO -- : Q-task_id([miq_provision_1]) MIQ(MiqQueue#delivered) Message id: [2088], State: [ok], Delivered in [4.626271782] seconds
https://github.com/ManageIQ/ovirt/pull/38
https://github.com/ManageIQ/manageiq/pull/5004
New commit detected on ManageIQ/manageiq/master: https://github.com/ManageIQ/manageiq/commit/a1409f725e7d6fe00e4477ec6e66f5cb5bdded87 commit a1409f725e7d6fe00e4477ec6e66f5cb5bdded87 Author: Brandon Dunne <bdunne> AuthorDate: Tue Oct 20 18:06:29 2015 -0400 Commit: Brandon Dunne <bdunne> CommitDate: Thu Oct 22 14:18:44 2015 -0400 Use Ovirt v0.7.0 which properly parses 200 - 206 response codes https://bugzilla.redhat.com/show_bug.cgi?id=1265466 gems/pending/Gemfile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
https://github.com/ManageIQ/manageiq/pull/5054
*** Bug 1267758 has been marked as a duplicate of this bug. ***
Verified in 5.5.0.11
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