Bug 1265466

Summary: rhev clone template provisioning fails
Product: Red Hat CloudForms Management Engine Reporter: Dave Johnson <dajohnso>
Component: ProvisioningAssignee: Brandon Dunne <bdunne>
Status: CLOSED ERRATA QA Contact: Pete Savage <psavage>
Severity: high Docs Contact:
Priority: high    
Version: 5.5.0CC: jhardy, mfeifer, nachandr, obarenbo, psavage
Target Milestone: GA   
Target Release: 5.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: rhev
Fixed In Version: 5.5.0.8 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-12-08 13:32:51 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 Dave Johnson 2015-09-23 02:22:34 UTC
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

Comment 2 CFME Bot 2015-10-20 20:43:27 UTC
https://github.com/ManageIQ/ovirt/pull/38

Comment 4 CFME Bot 2015-10-23 15:57:55 UTC
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(-)

Comment 6 Nandini Chandra 2015-11-17 18:35:22 UTC
*** Bug 1267758 has been marked as a duplicate of this bug. ***

Comment 7 Pete Savage 2015-11-20 14:23:06 UTC
Verified in 5.5.0.11

Comment 9 errata-xmlrpc 2015-12-08 13:32:51 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/RHSA-2015:2551