Bug 1469498

Summary:

[v2v] request timeout is very long (~2 days)

Product:

Red Hat CloudForms Management Engine

Reporter:

Ilanit Stein <istein>

Component:

Providers

Assignee:

Shmuel Melamud <smelamud>

Status:

CLOSED CURRENTRELEASE

QA Contact:

Ilanit Stein <istein>

Severity:

high

Docs Contact:

Priority:

high

Version:

5.8.0

CC:

cpelland, dajohnso, gblomqui, jfrey, jhardy, nsimsolo, obarenbo, pkliczew, smelamud, tjelinek

Target Milestone:

Keywords:

TestOnly, ZStream

Target Release:

5.9.0

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

rhev:v2v

Fixed In Version:

5.9.0.1

Doc Type:

If docs needed, set a value

Doc Text:

Story Points:

---

Clone Of:

Clones:

1479454 (view as bug list)

Environment:

Last Closed:

2018-03-06 15:27:25 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

Bug

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

RHEVM

Target Upstream Version:

Embargoed:

Bug Depends On:

Bug Blocks:

1479454

Attachments:

Description	Flags
automation.log	none
production.log	none
rhevm.log	none
evm.log	none

Description Ilanit Stein 2017-07-11 12:00:59 UTC

Description of problem:
On CFME-5.8.1 all v2v (Transform VM from RHV to VMWare) requests fail.
Even those that have the VM imported successfully.
Those requests fail after ~2 days, with this last massage:

"[EVM] VM [<imported VM name>] Step [WaitForImport] Status [Error in checking for VM Import completion] Message [Checking for VM Import completion]"

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

Expected:
v2v request timeout should be much shorter than 2 days.

Addtional info
I assume request fail after 100 retries, as after 1 day the retry number is 50.

Comment 2 Ilanit Stein 2017-07-11 12:38:24 UTC

Created attachment 1296241 [details]
automation.log

Comment 3 Ilanit Stein 2017-07-11 12:38:45 UTC

Created attachment 1296242 [details]
production.log

Comment 4 Ilanit Stein 2017-07-11 12:39:06 UTC

Created attachment 1296243 [details]
rhevm.log

Comment 5 Ilanit Stein 2017-07-11 12:39:33 UTC

Created attachment 1296244 [details]
evm.log

Comment 6 Piotr Kliczewski 2017-07-11 15:14:22 UTC

It looks like the issue is the same as in BZ #1467795:

[----] I, [2017-07-10T10:30:38.981496 #2834:40914c]  INFO -- : <AutomationEngine> <AEMethod [/ManageIQ/System/Event/EmsEvent/RHEVM/update_vm_import_status]> Starting 
[----] I, [2017-07-10T10:30:39.174154 #2865:40914c]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 1.
[----] I, [2017-07-10T10:30:39.194829 #2865:40914c]  INFO -- : MIQ(MiqQueue.put) Message id: [99457],  id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[----] E, [2017-07-10T10:30:39.890373 #2834:7f7b28] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status> The following error occurred during method evaluation:
[----] E, [2017-07-10T10:30:39.895550 #2834:7f7b28] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status>   DRb::DRbRemoteError: Service Model not found (MiqAeException::ServiceNotFound)
[----] E, [2017-07-10T10:30:39.939998 #2834:7f7b28] ERROR -- : <AutomationEngine> <AEMethod update_vm_import_status>   (druby://127.0.0.1:35931) /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:35931) /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:35931) /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:35931) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block'
(druby://127.0.0.1:35931) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1584:in `perform'
(druby://127.0.0.1:35931) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop'
(druby://127.0.0.1:35931) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1653:in `loop'
(druby://127.0.0.1:35931) /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-10T10:30:39.958110 #2834:7f7b28] ERROR -- : <AutomationEngine> Method STDERR: (druby://127.0.0.1:35931) /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 7 Tomas Jelinek 2017-08-07 14:02:55 UTC

patch merged to master: https://github.com/ManageIQ/manageiq-content/pull/149

Comment 9 Ilanit Stein 2018-01-02 07:48:11 UTC

Verified on CFME-5.9.0.14/RHV-4.1.8

CFME Failing VM import requests, do not have such long timeout.
For example Windows VM import request, failing to mount, will end up after few minutes.