Bug 1467795 - [v2v] operation fail on Invalid ISO image path
[v2v] operation fail on Invalid ISO image path
Status: VERIFIED
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Providers (Show other bugs)
5.8.0
Unspecified Unspecified
high Severity urgent
: GA
: 5.9.0
Assigned To: Tomas Jelinek
Ilanit Stein
rhev:v2v
: TestOnly, ZStream
Depends On:
Blocks: 1469174
  Show dependency treegraph
 
Reported: 2017-07-05 03:57 EDT by Ilanit Stein
Modified: 2018-01-02 03:52 EST (History)
12 users (show)

See Also:
Fixed In Version: 5.9.0.1
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1469174 (view as bug list)
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: Bug
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: RHEVM


Attachments (Terms of Use)
production.log (52.57 KB, application/x-gzip)
2017-07-05 07:56 EDT, Ilanit Stein
no flags Details
automation.log (1.93 MB, application/x-gzip)
2017-07-05 07:57 EDT, Ilanit Stein
no flags Details
evm.log (702.78 KB, application/x-gzip)
2017-07-05 07:57 EDT, Ilanit Stein
no flags Details
engine.log (207.48 KB, application/x-gzip)
2017-07-05 07:58 EDT, Ilanit Stein
no flags Details

  None (edit)
Description Ilanit Stein 2017-07-05 03:57:39 EDT
Description of problem:
Transform a VM from RHV to VMWare (v2v) fails instantly, 
on "Operation Failed: [Invalid ISO image path], 
seen on RHV engine.log.
However, on CFME side, automate->Requests so not reflect this error.

The request's Last message (after 1 hour):
"[EVM] VM [test_v2v_rhel_7_2_automation_vmware_5GB] Step [WaitForImport] Status [VM Import completed] Message [Checking for VM Import completion] Current Retry Number [3]"

Version-Release number of selected component (if applicable):
CFME-5.8.1.0/RHV-4.1.3

How reproducible:
100%
Tried once without install drivers option, and once with install drivers,
and go the same result.

Additional info:
RHV: engine.log:
===============
2017-07-05 10:37:34,950+03 INFO  [org.ovirt.engine.core.bll.exportimport.ImportVmFromExternalUrlCommand] (default task-27) [697a6c4d-aade-43b2-8b41-ebfe82265557] Running command: ImportVmFromExternalUrlCommand internal: false. Entities affected :  ID: c7e2d2fa-40ec-43af-9e61-9231349440a8 Type: StorageAction group IMPORT_EXPORT_VM with role type ADMIN
2017-07-05 10:37:34,956+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVmsFullInfoFromExternalProviderVDSCommand] (default task-27) [697a6c4d-aade-43b2-8b41-ebfe82265557] START, GetVmsFullInfoFromExternalProviderVDSCommand(HostName = host_mixed_2, GetVmsFromExternalProviderParameters:{runAsync='true', hostId='3b2f783a-0168-4629-b8ef-721bd3517b2b', url='vpx://administrator@10.35.5.21/Folder1%2FFolder2%2FCompute3%2FFolder4%2FCluster5/10.35.72.10?no_verify=1', username='administrator', originType='VMWARE', namesOfVms='[test_v2v_rhel_7_2_automation_vmware_5GB]'}), log id: 12955d58
2017-07-05 10:37:36,680+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVmsFullInfoFromExternalProviderVDSCommand] (default task-27) [697a6c4d-aade-43b2-8b41-ebfe82265557] FINISH, GetVmsFullInfoFromExternalProviderVDSCommand, return: [VM [test_v2v_rhel_7_2_automation_vmware_5GB]], log id: 12955d58
2017-07-05 10:37:36,723+03 INFO  [org.ovirt.engine.core.bll.exportimport.ImportVmFromExternalProviderCommand] (default task-27) [473b30bf] Lock Acquired to object 'EngineLock:{exclusiveLocks='[42357efd-1a93-dc25-9257-bac0fa6a4daf=VM, v2v_with_drivers=VM_NAME]', sharedLocks=''}'
2017-07-05 10:37:36,788+03 WARN  [org.ovirt.engine.core.bll.exportimport.ImportVmFromExternalProviderCommand] (default task-27) [] Validation of action 'ImportVmFromExternalProvider' failed for user admin@internal-authz. Reasons: VAR__ACTION__IMPORT,VAR__TYPE__VM,ERROR_CANNOT_FIND_ISO_IMAGE_PATH
2017-07-05 10:37:36,790+03 INFO  [org.ovirt.engine.core.bll.exportimport.ImportVmFromExternalProviderCommand] (default task-27) [] Lock freed to object 'EngineLock:{exclusiveLocks='[42357efd-1a93-dc25-9257-bac0fa6a4daf=VM, v2v_with_drivers=VM_NAME]', sharedLocks=''}'
2017-07-05 10:37:36,799+03 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-27) [] Operation Failed: [Invalid ISO image path]

CFME: automation.log:
====================

[----] I, [2017-07-05T03:36:33.793810 #15440:9ebc68]  INFO -- : Updated namespace [Infrastructure/VM/Transform/Import/list_driver_isos  ManageIQ/Infrastructure/VM/Transform]
[----] I, [2017-07-05T03:36:33.800983 #15440:9ebc68]  INFO -- : Invoking [inline] method [/ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos] with inputs [{}]
[----] I, [2017-07-05T03:36:33.801859 #15440:9ebc68]  INFO -- : <AEMethod [/ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos]> Starting 
[----] E, [2017-07-05T03:36:34.315624 #15440:942c80] ERROR -- : <AEMethod list_driver_isos> The following error occurred during method evaluation:
[----] E, [2017-07-05T03:36:34.317595 #15440:942c80] ERROR -- : <AEMethod list_driver_isos>   NoMethodError: undefined method `iso_images' for nil:NilClass
[----] E, [2017-07-05T03:36:34.318106 #15440:942c80] ERROR -- : <AEMethod list_driver_isos>   /ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos:21:in `main'
[----] E, [2017-07-05T03:36:34.321683 #15440:942c80] ERROR -- : Method STDERR: /ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos:21:in `main': undefined method `iso_images' for nil:NilClass (NoMethodError)
[----] E, [2017-07-05T03:36:34.322385 #15440:942c80] ERROR -- : Method STDERR:  from /ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos:44:in `<main>'
[----] I, [2017-07-05T03:36:34.352103 #15440:9ebc68]  INFO -- : <AEMethod [/ManageIQ/Infrastructure/VM/Transform/Import/list_driver_isos]> Ending
[----] E, [2017-07-05T03:36:34.352798 #15440:9ebc68] ERROR -- : Aborting instantiation (unknown method return code) because [Method exited with rc=Unknown RC: [1]]
[----] I, [2017-07-05T03:37:18.550833 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Instantiating [/SYSTEM/REQUEST/import_vm?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&VmOrTemplate%3A%3Avm=20&dialog_cluster=2&dialog_drivers_iso=&dialog_install_drivers=t&dialog_name=v2v_with_drivers&dialog_provider=1&dialog_sparse=t&dialog_storage=5&object_name=import_vm&vmdb_object_type=vm]
[----] I, [2017-07-05T03:37:18.577653 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Updated namespace [/SYSTEM/REQUEST/import_vm?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&VmOrTemplate%3A%3Avm=20&dialog_cluster=2&dialog_drivers_iso=&dialog_install_drivers=t&dialog_name=v2v_with_drivers&dialog_provider=1&dialog_sparse=t&dialog_storage=5&object_name=import_vm&vmdb_object_type=vm  ManageIQ/SYSTEM]
[----] I, [2017-07-05T03:37:18.632919 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Following Relationship [miqaedb:/Infrastructure/VM/Transform/Import/ImportVm#create]
[----] I, [2017-07-05T03:37:18.653568 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Updated namespace [miqaedb:/Infrastructure/VM/Transform/Import/ImportVm#create  ManageIQ/Infrastructure/VM/Transform]
[----] I, [2017-07-05T03:37:18.675357 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Updated namespace [Infrastructure/VM/Transform/Import/create_vm_import_request  ManageIQ/Infrastructure/VM/Transform]
[----] I, [2017-07-05T03:37:18.683277 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Invoking [inline] method [/ManageIQ/Infrastructure/VM/Transform/Import/create_vm_import_request] with inputs [{}]
[----] I, [2017-07-05T03:37:18.684859 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) <AEMethod [/ManageIQ/Infrastructure/VM/Transform/Import/create_vm_import_request]> Starting 
[----] I, [2017-07-05T03:37:19.521573 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) <AEMethod [/ManageIQ/Infrastructure/VM/Transform/Import/create_vm_import_request]> Ending
[----] I, [2017-07-05T03:37:19.521818 #15358:943130]  INFO -- : Q-task_id([resource_action_41]) Method exited with rc=MIQ_OK
Comment 2 Ilanit Stein 2017-07-05 06:19:13 EDT
It turns out that this failure occur due to an obligatory requirement of virtio-win....iso driver.

When an ISO domain was added to the RHV environment, 
that contain virtio-win-1.9.0.iso,
the Transform of a VM from VMWare to RHV work, 
and do not fail on "Invalid ISO image path".

Therefore, there are 2 problems that need to be fixed within this bug:

1. A notification on the v2v dialog, on the obligatory requirement of virtio-win....iso driver, that should be attached to the RHV provider.

2. An Error in UI, on that the v2v operation failed on missing virtio-win driver.

Comment: 
* On RHV side, the v2v dialog allow choosing the driver, and it is set to virtio-win driver, by default.
If on CFME v2v dialog, this driver option will be added, than it can force a driver, and this can serve as a solution to problem 1 mentioned above.  

Arik,
Why on the virtio-win driver is a "must" requirement for a RHEL-7.2 VM transform from VMWare to RHV please?
Comment 3 Arik 2017-07-05 06:46:54 EDT
(In reply to Ilanit Stein from comment #2)
> Arik,
> Why on the virtio-win driver is a "must" requirement for a RHEL-7.2 VM
> transform from VMWare to RHV please?

It is not required for the conversion of non-windows VMs.
The problem you mentioned above "Invalid ISO image path" is generated when the client pass the name of an iso to use and the iso domain is not available. If the request from CFME won't contain the name of the iso in the parameters, this error won't happen.
Comment 4 Ilanit Stein 2017-07-05 07:56 EDT
Created attachment 1294550 [details]
production.log
Comment 5 Ilanit Stein 2017-07-05 07:57 EDT
Created attachment 1294551 [details]
automation.log
Comment 6 Ilanit Stein 2017-07-05 07:57 EDT
Created attachment 1294552 [details]
evm.log
Comment 7 Ilanit Stein 2017-07-05 07:58 EDT
Created attachment 1294553 [details]
engine.log
Comment 8 Martin Betak 2017-07-10 04:11:26 EDT
@Ilanit for this setup:

1) is the target RHV provider configured with ISO domain (on the ManageIQ level)
2) is the domain refreshed with up to date image list?
Comment 9 Ilanit Stein 2017-07-10 06:22:22 EDT
1) No.
2) Not relevant, as no ISO domain was added on ManageIQ side.

At first the RHV provider contained 2 in active ISO domains,
and when trying to run v2v, it failed immediately on: "Invalid ISO image path".

Then ISO domain was added to the RHV provider. It contains also a virtio-win driver.

With this added ISO domain, the v2v operation worked.
Comment 10 Martin Betak 2017-07-10 10:23:03 EDT
Fix posted u/s https://github.com/ManageIQ/manageiq-providers-ovirt/pull/59
Comment 11 Martin Betak 2017-07-10 11:02:11 EDT
Note: current workaround is to configure an ISO domain for the target RHV infra provider in CFME->Compute->PXE->ISO domain
Comment 12 Martin Betak 2017-07-10 11:09:21 EDT
merged u/s
Comment 14 Piotr Kliczewski 2017-07-11 11:10:28 EDT
I checked the logs and the event is handled properly. The refresh is triggered but there is following issue in the logs which needs to be handled:

[----] I, [2017-07-05T05:27:02.795471 #15358:943130]  INFO -- : <AutomationEngine> Invoking [inline] method [/ManageIQ/System/Event/EmsEvent/RHEVM/update_vm_import_status] with inputs [{}]
[----] I, [2017-07-05T05:27:02.796959 #15358:943130]  INFO -- : <AutomationEngine> <AEMethod [/ManageIQ/System/Event/EmsEvent/RHEVM/update_vm_import_status]> Starting 
[----] E, [2017-07-05T05:27:03.337980 #15358:ed6d40] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status> The following error occurred during method evaluation:
[----] E, [2017-07-05T05:27:03.338681 #15358:ed6d40] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status>   DRb::DRbRemoteError: Service Model not found (MiqAeException::ServiceNotFound)
[----] E, [2017-07-05T05:27:03.339643 #15358:ed6d40] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status>   (druby://127.0.0.1:32798) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_method_service/miq_ae_service_model_base.rb:21:in `rescue in method_missing'
(druby://127.0.0.1:32798) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_method_service/miq_ae_service_model_base.rb:18:in `method_missing'
(druby://127.0.0.1:32798) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_method_service/miq_ae_service_vmdb.rb:5:in `vmdb'
(druby://127.0.0.1:32798) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block'
(druby://127.0.0.1:32798) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1584:in `perform'
(druby://127.0.0.1:32798) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop'
(druby://127.0.0.1:32798) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1653:in `loop'
(druby://127.0.0.1:32798) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1653:in `block in main_loop'
/ManageIQ/System/Event/EmsEvent/RHEVM/update_vm_import_status:28:in `vm'
/ManageIQ/System/Event/EmsEvent/RHEVM/update_vm_import_status:13:in `main'
[----] E, [2017-07-05T05:27:03.343828 #15358:ed6d40] ERROR -- : <AutomationEngine> Method STDERR: (druby://127.0.0.1:32798) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_method_service/miq_ae_service_model_base.rb:21:in `rescue in method_missing': Service Model not found (MiqAeException::ServiceNotFound) (DRb::DRbRemoteError)
Comment 15 Ilanit Stein 2018-01-02 03:52:45 EST
Verified on CFME-5.9.0.14/RHV-4.1.8.

This BZ is relevant only for Windows VMs, that require drivers install.

In case a Windows VM is imported, on the v2v CFME dialog, it is not possible to submit the form, without choosing a driver, from ISO domain.
It fails with validation error:
"Main/Transform Virtual Machine/Drivers is required"

Therefore, sending an empty ISO path is blocked in the CFME v2v dialog stage.

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