Bug 1688465

[root@dhcp-8-196-184 log]# tailf automation.log | grep "ERROR" [----] E, [2019-03-13T14:40:11.158216 #5607:1711230] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) <AEMethod poweroff> The following error occurred during method evaluation:
[----] E, [2019-03-13T14:40:11.158774 #5607:1711230] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) <AEMethod poweroff>   RuntimeError: VM 'ytale-ubuntu-13march-002 is powered on, but we are not allowed to shut it down. Aborting.
[----] E, [2019-03-13T14:40:11.159685 #5607:1711230] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) <AEMethod poweroff>   /ManageIQ/Transformation/Infrastructure/VM/Common/PowerOff:16:in `main'
[----] E, [2019-03-13T14:40:11.168614 #5607:1711230] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) Method STDERR: /ManageIQ/Transformation/Infrastructure/VM/Common/PowerOff:16:in `main': VM 'ytale-ubuntu-13march-002 is powered on, but we are not allowed to shut it down. Aborting. (RuntimeError)
[----] E, [2019-03-13T14:40:11.169114 #5607:1711230] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) Method STDERR:     from /ManageIQ/Transformation/Infrastructure/VM/Common/PowerOff:36:in `<main>'
[----] E, [2019-03-13T14:40:11.197103 #5607:ecef50] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) Aborting instantiation (unknown method return code) because [Method exited with rc=Unknown RC: [1]]
[----] E, [2019-03-13T14:40:11.197540 #5607:ecef50] ERROR -- : Q-task_id([r9_service_template_transformation_plan_task_11]) State=<State5> running  raised exception: <Method exited with rc=Unknown RC: [1]>

https://github.com/ManageIQ/manageiq-content/pull/513

Tested CFME-5.10.2.0/RHV-4.3.1
Did not succeed migrating a single VM.

Added this patch:
 https://patch-diff.githubusercontent.com/raw/ManageIQ/manageiq-providers-ovirt/pull/343.patch
To overcome RHV-4.3.0,4.3.1 refresh bug: https://bugzilla.redhat.com/show_bug.cgi?id=1668720, that was resolved only in RHV-4.3.2

Checked app/models/service_template_transformation_plan_task.rb content:
To verify it contains a fix for Bug 1686049 - [v2v][RHV] Migration to RHV failed, with Status: Assess Migration
 

  def calculate_network_mappings
    source.hardware.nics.select { |n| n.device_type == 'ethernet' }.collect do |nic|
      source_network = nic.lan
      destination_network = transformation_destination(source_network)
      raise "[#{source.name}] NIC #{nic.device_name} [#{source_network.name}] has no mapping." if destination_network.nil?
      {
        :source      => source_network.name,
        :destination => destination_network_ref(destination_network),
        :mac_address => nic.address,
        :ip_address  => nic.network.try(:ipaddress)
      }.compact
    end
  end


In CFME UI: After running "Migrate", the migration plan was approved, but then it begun waiting for conversion host.
automation.log show "Waiting for PreflightCheck", "message"=>"State5 is not finished yet [7/86400 retries]."



[----] I, [2019-03-17T07:25:10.631271 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) User [admin] with current group ID [2] name [EvmGroup-super_administrator]
[----] I, [2019-03-17T07:25:10.705777 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Instantiating [/Transformation/StateMachines/VMTransformation/Transformation?MiqServer%3A%3Amiq_server=1&ServiceTemplateTransformationPlanTask%3A%3Aservice_template_transformation_plan_task=5&User%3A%3Auser=1&ae_state=State5&ae_state_data=---%20%21ruby%2Fhash%3AActiveSupport%3A%3AHashWithIndifferentAccess%0Aae_state_progress%3A%20%0A&ae_state_previous=---%0A%22%2FManageIQ%2FTransformation%2FStateMachines%2FVMTransformation%2FTransformation%22%3A%0A%20%20ae_state%3A%20State5%0A%20%20ae_state_retries%3A%207%0A%20%20ae_state_started%3A%202019-03-17%2011%3A22%3A26%20UTC%0A%20%20ae_state_max_retries%3A%2086400%0A&ae_state_retries=7&ae_state_started=2019-03-17%2011%3A22%3A26%20UTC&object_name=Transformation&request=transformation_plan&service_action=Provision&vmdb_object_type=service_template_transformation_plan_task#create]
[----] I, [2019-03-17T07:25:11.125684 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [/Transformation/StateMachines/VMTransformation/Transformation?MiqServer%3A%3Amiq_server=1&ServiceTemplateTransformationPlanTask%3A%3Aservice_template_transformation_plan_task=5&User%3A%3Auser=1&ae_state=State5&ae_state_data=---%20%21ruby%2Fhash%3AActiveSupport%3A%3AHashWithIndifferentAccess%0Aae_state_progress%3A%20%0A&ae_state_previous=---%0A%22%2FManageIQ%2FTransformation%2FStateMachines%2FVMTransformation%2FTransformation%22%3A%0A%20%20ae_state%3A%20State5%0A%20%20ae_state_retries%3A%207%0A%20%20ae_state_started%3A%202019-03-17%2011%3A22%3A26%20UTC%0A%20%20ae_state_max_retries%3A%2086400%0A&ae_state_retries=7&ae_state_started=2019-03-17%2011%3A22%3A26%20UTC&object_name=Transformation&request=transformation_plan&service_action=Provision&vmdb_object_type=service_template_transformation_plan_task#create  ManageIQ/Transformation/StateMachines]
[----] I, [2019-03-17T07:25:11.451739 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) In State=[State5], invoking [on_entry] method=[/System/CommonMethods/MiqAe.WeightedUpdateStatus(weight => 1, description => "Waiting for PreflightCheck", task_message => "Pre-migration")]
[----] I, [2019-03-17T07:25:11.470741 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [system/commonmethods/miqae/weightedupdatestatus  ManageIQ/system/commonmethods]
[----] I, [2019-03-17T07:25:11.523304 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Invoking [inline] method [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus] with inputs [{"weight"=>1, "description"=>"Waiting for PreflightCheck", "task_message"=>"Pre-migration"}]
[----] I, [2019-03-17T07:25:11.526123 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus]> Starting 
[----] I, [2019-03-17T07:25:12.416939 #9539:fcebbc]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod weightedupdatestatus> State Hash: {"status"=>"active", "weight"=>1, "description"=>"Waiting for PreflightCheck", "message"=>"State5 is not finished yet [7/86400 retries].", "started_on"=>2019-03-17 11:22:27 UTC, "percent"=>0.008101851851851851, "updated_on"=>2019-03-17 11:24:52 UTC}
[----] I, [2019-03-17T07:25:12.540902 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus]> Ending
[----] I, [2019-03-17T07:25:12.541104 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Method exited with rc=MIQ_OK
[----] I, [2019-03-17T07:25:12.541724 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Processing State=[State5]
[----] I, [2019-03-17T07:25:12.542227 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Following Relationship [miqaedb:/Transformation/Common/PreflightCheck#create]
[----] I, [2019-03-17T07:25:12.567984 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [miqaedb:/Transformation/Common/PreflightCheck#create  ManageIQ/Transformation]
[----] I, [2019-03-17T07:25:12.593486 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Instance [/ManageIQ/Transformation/Common/PreflightCheck] not found in MiqAeDatastore - trying [.missing]
[----] I, [2019-03-17T07:25:12.604619 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [Transformation/Common/preflightcheck  ManageIQ/Transformation]
[----] I, [2019-03-17T07:25:12.616291 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Invoking [inline] method [/ManageIQ/Transformation/Common/PreflightCheck] with inputs [{}]
[----] I, [2019-03-17T07:25:12.622448 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [Transformation/Common/Utils  ManageIQ/Transformation]
[----] I, [2019-03-17T07:25:12.647532 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Loading embedded method /ManageIQ/Transformation/Common/Utils
[----] I, [2019-03-17T07:25:12.649752 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/Transformation/Common/PreflightCheck]> Starting 
[----] I, [2019-03-17T07:25:13.269887 #9539:aedd5c8]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod preflightcheck> PreflightCheck: task.state: active
[----] I, [2019-03-17T07:25:13.312372 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/Transformation/Common/PreflightCheck]> Ending
[----] I, [2019-03-17T07:25:13.312556 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Method exited with rc=MIQ_OK
[----] I, [2019-03-17T07:25:13.313189 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Followed  Relationship [miqaedb:/Transformation/Common/PreflightCheck#create]
[----] I, [2019-03-17T07:25:13.313341 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Processed State=[State5] with Result=[retry]
[----] I, [2019-03-17T07:25:13.313624 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) In State=[State5], invoking [on_exit] method=[/System/CommonMethods/MiqAe.WeightedUpdateStatus(weight => 1, description => "Waiting for PreflightCheck", task_message => "Pre-migration")]
[----] I, [2019-03-17T07:25:13.329015 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Updated namespace [system/commonmethods/miqae/weightedupdatestatus  ManageIQ/system/commonmethods]
[----] I, [2019-03-17T07:25:13.410412 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Invoking [inline] method [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus] with inputs [{"weight"=>1, "description"=>"Waiting for PreflightCheck", "task_message"=>"Pre-migration"}]
[----] I, [2019-03-17T07:25:13.413706 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus]> Starting 
[----] I, [2019-03-17T07:25:14.043918 #9539:a55ddb8]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod weightedupdatestatus> State Hash: {"status"=>"active", "weight"=>1, "description"=>"Waiting for PreflightCheck", "message"=>"State5 is not finished yet [8/86400 retries].", "started_on"=>2019-03-17 11:22:27 UTC, "percent"=>0.009259259259259259, "updated_on"=>2019-03-17 11:25:14 UTC}
[----] I, [2019-03-17T07:25:14.178171 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) <AEMethod [/ManageIQ/System/CommonMethods/MiqAe/WeightedUpdateStatus]> Ending
[----] I, [2019-03-17T07:25:14.178368 #9539:d7cf58]  INFO -- : Q-task_id([r5_service_template_transformation_plan_task_5]) Method exited with rc=MIQ_OK


Not sure what is failing the preflight check.
Unclear if the Bug 1686049 (VMware VM has no ip address) can be verified.

Fixed! Verified on: 5.11.0.8.20190611155126_01e077e

Please note 5.11.0.8 don't have v2v-conversion-ansible package and hence migration not working with that but I have installed package manually and migration is working.
We are tracking that issue under BZ1720614.