Problem: When provisioning new VMs to RHV the VM is provisioned but then Foreman immediately rolls back with the error “Could not find virtual machine network interface matching xxx.xxx.xxx.xxx”
Expected outcome: VM is provisioned with proper network interface configuration
Foreman and Proxy versions: Foreman 3.4.1, Foreman-Proxy 3.4.1
Foreman and Proxy plugin versions: foreman-ovirt-3.4.1, rubygem-fog-ovirt-2.0.2, rubygem-ovirt-engine-sdk-4.4.1
Distribution and version: RHEL 8.7, RHV 4.3.11
Other relevant data:
Here is the relevant lines from production.log when attempting to provision a VM. I have obscured IP addresses and tokens. The rollback fails because the disk attached to the VM is still in the process of being provisioned but I don’t think that is relevant to the problem causing the rollback.
2022-12-07T14:25:53 [I|app|8b0f4ad9] Started POST "/hosts" for xx.xx.xx.11 at 2022-12-07 14:25:53 -0600
2022-12-07T14:25:53 [I|app|8b0f4ad9] Processing by HostsController#create as */*
2022-12-07T14:25:53 [I|app|8b0f4ad9] Parameters: {"utf8"=>"✓", "authenticity_token"=>"*************************", "host"=>{"name"=>"janet-orrego", "organization_id"=>"1", "location_id"=>"2", "hostgroup_id"=>"", "compute_resource_id"=>"3", "compute_profile_id"=>"1", "puppet_attributes"=>{"environment_id"=>"1"}, "puppet_proxy_id"=>"1", "puppet_ca_proxy_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "identifier"=>"", "name"=>"janet-orrego", "domain_id"=>"1", "subnet_id"=>"1", "ip"=>"xx.xx.xx.101", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"name"=>"", "vnic_profile"=>"980a5d7b-7682-462c-b891-3ef05e538d56"}}}, "compute_attributes"=>{"cluster"=>"f1e52902-29e9-4351-b2cf-13100cb1d366", "template"=>"", "instance_type"=>"", "cores"=>"2", "sockets"=>"1", "memory"=>"3221225472", "ha"=>"0", "start"=>"0", "display"=>{"type"=>"spice", "keyboard_layout"=>"en-us"}, "volumes_attributes"=>{"0"=>{"_delete"=>"", "size_gb"=>"20", "storage_domain"=>"4a113ac7-4d2e-47cf-a646-c75d16170d80", "id"=>"", "preallocate"=>"1", "wipe_after_delete"=>"1", "interface"=>"virtio_scsi", "bootable"=>"true"}}}, "architecture_id"=>"1", "operatingsystem_id"=>"2", "provision_method"=>"build", "build"=>"1", "medium_id"=>"12", "ptable_id"=>"131", "pxe_loader"=>"PXELinux BIOS", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}}
2022-12-07T14:25:53 [W|api|8b0f4ad9] param host[puppetclass_*] has been deprecated in favor of host[puppet_attributes][puppetclass_*]
2022-12-07T14:25:54 [W|app|8b0f4ad9] Scoped order is ignored, it's forced to be batch order.
2022-12-07T14:25:54 [I|app|8b0f4ad9] Adding Compute instance for janet-orrego.ucs.louisiana.edu
2022-12-07T14:25:55 [I|app|7387c07f] Started GET "/tasks/ee659232-a83d-4768-a466-3b82d80bc688" for xx.xx.xx.11 at 2022-12-07 14:25:55 -0600
2022-12-07T14:25:55 [I|app|7387c07f] Processing by TasksController#show as */*
2022-12-07T14:25:55 [I|app|7387c07f] Parameters: {"id"=>"ee659232-a83d-4768-a466-3b82d80bc688"}
2022-12-07T14:25:55 [I|app|7387c07f] Completed 200 OK in 13ms (Views: 3.0ms | ActiveRecord: 2.5ms | Allocations: 2872)
2022-12-07T14:25:56 [W|app|8b0f4ad9] Orchestration::Compute: Could not match network interface #<Nic::Managed id: nil, mac: nil, ip: "xx.xx.xx.101", type: "Nic::Managed", name: "janet-orrego.ucs.louisiana.edu", host_id: nil, subnet_id: 1, domain_id: 1, attrs: {}, created_at: nil, updated_at: nil, provider: nil, username: nil, password: nil, virtual: false, link: true, identifier: "", tag: "", attached_to: "", managed: true, mode: "balance-rr", attached_devices: "", bond_options: "", primary: true, provision: true, compute_attributes: {"name"=>"", "vnic_profile"=>"980a5d7b-7682-462c-b891-3ef05e538d56"}, ip6: "", subnet6_id: nil>
2022-12-07T14:25:56 [W|app|8b0f4ad9] Could not find virtual machine network interface matching xx.xx.xx.101
2022-12-07T14:25:56 [W|app|8b0f4ad9] Rolling back due to a problem: [#<Orchestration::Task:0x00005586e1c5c4f8 @name="Query instance details for janet-orrego.ucs.louisiana.edu", @id="Query instance details for janet-orrego.ucs.louisiana.edu", @status="failed", @priority=5, @action=[#<Host::Managed id: nil, name: "janet-orrego.ucs.louisiana.edu", last_compile: nil, last_report: nil, updated_at: nil, created_at: nil, root_pass: [FILTERED], architecture_id: 1, operatingsystem_id: 2, ptable_id: 131, medium_id: 12, build: true, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: nil, owner_id: 4, owner_type: "User", enabled: true, puppet_ca_proxy_id: 1, managed: true, use_image: nil, image_file: nil, uuid: "c11777b5-1b9f-4a2a-9eb6-32c5b01d6f34", compute_resource_id: 3, puppet_proxy_id: 1, certname: nil, image_id: nil, organization_id: 1, location_id: 2, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 1, provision_method: "build", grub_pass: nil, global_status: 0, lookup_value_matcher: [FILTERED], pxe_loader: "PXELinux BIOS", initiated_at: nil, build_errors: nil>, :setComputeDetails], @created=1670444754.3020089, @timestamp=2022-12-07 20:25:56.812466496 UTC>]
2022-12-07T14:25:56 [I|app|8b0f4ad9] Removing Compute instance for janet-orrego.ucs.louisiana.edu
2022-12-07T14:25:57 [W|app|8b0f4ad9] Failed to destroy a compute UCSS RHV (oVirt) instance janet-orrego.ucs.louisiana.edu: Fault reason is "Operation Failed". Fault detail is "[Cannot remove VM: The following disks are locked: janet-orrego.ucs.louisiana.edu_Disk1. Please try again in a few minutes.]". HTTP response code is 409.