Bug 1452157

Summary: Wrong RHV provider refresh error, when provider is down.
Product: Red Hat CloudForms Management Engine Reporter: Ilanit Stein <istein>
Component: ProvidersAssignee: Piotr Kliczewski <pkliczew>
Status: CLOSED CURRENTRELEASE QA Contact: Radim Hrazdil <rhrazdil>
Severity: high Docs Contact:
Priority: high    
Version: 5.8.0CC: jfrey, jhardy, obarenbo, rhrazdil
Target Milestone: GAKeywords: TestOnly, ZStream
Target Release: 5.9.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: rhev
Fixed In Version: 5.9.0.1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1461559 (view as bug list) Environment:
Last Closed: 2018-03-06 14:36:58 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: 1461559    

Description Ilanit Stein 2017-05-18 12:54:21 UTC 
Description of problem:
Have a RHV provider, connected to CFME.
Power OFF the RHV provider
In the provider summary page, in "Last refresh" field, the error is:  
"Error - About 2 Hours Ago 
version 3 of the api is not supported by the provider "

Version-Release number of selected component (if applicable):
CFME-5.8.0.14
RHV-4.0.7

Expected results:
There should be a relevant message. The real problem is that the connection to the RHV provider is broken.

Additional info:

* boriso: "When the provider is off it does not support any version of the api."

* Part of the Error from attached evm.log:

----] E, [2017-05-18T05:57:40.077496 #12710:b0d13c] ERROR -- : <RHEVM> Ovirt::Service#resource_get: class = Errno::EHOSTUNREACH, message=Failed to open TCP connection to istein-rhv40.scl.lab.tlv.redhat.com:443 (No route to host - connect(2) for "istein-rhv40.scl.lab.tlv.redhat.com" port 443), URI=https://istein-rhv40.scl.lab.tlv.redhat.com/ovirt-engine/api
[----] W, [2017-05-18T05:57:40.078095 #12710:b0d13c]  WARN -- : MIQ(ManageIQ::Providers::Redhat::InfraManager#verify_credentials_for_rhevm) Failed to open TCP connection to istein-rhv40.scl.lab.tlv.redhat.com:443 (No route to host - connect(2) for "istein-rhv40.scl.lab.tlv.redhat.com" port 443)
[----] W, [2017-05-18T05:57:40.078220 #12710:b0d13c]  WARN -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::EventCatcher::Runner#start_event_monitor) EMS [istein-rhv40.scl.lab.tlv.redhat.com] as [admin@internal] Failed to open TCP connection to istein-rhv40.scl.lab.tlv.redhat.com:443 (No route to host - connect(2) for "istein-rhv40.scl.lab.tlv.redhat.com" port 443)
[----] I, [2017-05-18T05:57:41.069763 #12128:b0d13c]  INFO -- : MIQ(MiqServer#populate_queue_messages) Fetched 1 miq_queue rows for queue_name=ems_1, wcount=2, priority=200
[----] I, [2017-05-18T05:57:44.183063 #9371:b0d13c]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::RefreshWorker::Runner#get_message_via_drb) Message id: [29382], MiqWorker id: [88], Zone: [default], Role: [ems_inventory], Server: [], Ident: [ems_1], Target id: [], Instance id: [], Task id: [], Command: [EmsRefresh.refresh], Timeout: [7200], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [[["ManageIQ::Providers::Redhat::InfraManager", 1]]], Dequeued in: [7.86027643] seconds
[----] I, [2017-05-18T05:57:44.183325 #9371:b0d13c]  INFO -- : MIQ(MiqQueue#deliver) Message id: [29382], Delivering...
[----] I, [2017-05-18T05:57:44.192461 #9371:b0d13c]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) Refreshing all targets...
[----] I, [2017-05-18T05:57:44.192648 #9371:b0d13c]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) EMS: [istein-rhv], id: [1] Refreshing targets for EMS...
[----] I, [2017-05-18T05:57:44.192844 #9371:b0d13c]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) EMS: [istein-rhv], id: [1]   ManageIQ::Providers::Redhat::InfraManager [istein-rhv] id [1]
[----] I, [2017-05-18T05:57:46.244703 #15223:b0d13c]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 4.
[----] I, [2017-05-18T05:57:46.253836 #15223:b0d13c]  INFO -- : MIQ(MiqQueue.put) Message id: [29383],  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: []
[----] I, [2017-05-18T05:57:46.260561 #15223:b0d13c]  INFO -- : MIQ(MiqQueue.put) Message id: [29384],  id: [], Zone: [default], Role: [], Server: [fe097f36-39fc-11e7-a802-001a4a169312], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[----] I, [2017-05-18T05:57:46.269314 #15223:b0d13c]  INFO -- : MIQ(MiqQueue.put) Message id: [29385],  id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Job.check_jobs_for_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[----] E, [2017-05-18T05:57:47.218420 #9371:b0d13c] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager#supported_api_versions_from_sdk) Error while probing supported api versions Can't send request: Couldn't connect to server
[----] E, [2017-05-18T05:57:47.219812 #9371:b0d13c] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) EMS: [istein-rhv], id: [1] Refresh failed
[----] E, [2017-05-18T05:57:47.220581 #9371:b0d13c] ERROR -- : [RuntimeError]: version 3 of the api is not supported by the provider  Method:[rescue in block in refresh]
[----] E, [2017-05-18T05:57:47.221105 #9371:b0d13c] ERROR -- : /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/api_integration.rb:21:in `connect'
/var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/api_integration.rb:107:in `rhevm_inventory'
/var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/refresh/refresher.rb:51:in `inventory_from_ovirt'
/var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/refresh/refresher.rb:6:in `collect_inventory_for_targets'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:79:in `block in refresh_targets_for_ems'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:78:in `refresh_targets_for_ems'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:24:in `block (2 levels) in refresh'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:24:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:14:in `each'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:14:in `refresh'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:9:in `refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:98:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:97:in `each'
/var/www/miq/vmdb/app/models/ems_refresh.rb:97:in `refresh'
/var/www/miq/vmdb/app/models/miq_queue.rb:347:in `block in deliver'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:91:in `block in timeout'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `block in catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:106:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:107:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:135:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:153:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:336:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:333:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:333:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:155:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:130:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:21:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:339:in `block in start_runner'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:337:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:348:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:266:in `start_worker'
/var/www/miq/vmdb/app/models/mixins/per_ems_worker_mixin.rb:68:in `start_worker_for_ems'
/var/www/miq/vmdb/app/models/mixins/per_ems_worker_mixin.rb:46:in `block in sync_workers'
/var/www/miq/vmdb/app/models/mixins/per_ems_worker_mixin.rb:45:in `each'
/var/www/miq/vmdb/app/models/mixins/per_ems_worker_mixin.rb:45:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:22:in `monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:348:in `block in monitor'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:348:in `monitor'
/var/www/miq/vmdb/app/models/miq_server.rb:370:in `block (2 levels) in monitor_loop'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-e0f3ea8755bf/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:370:in `block in monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:369:in `loop'
/var/www/miq/vmdb/app/models/miq_server.rb:369:in `monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:252:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:91:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] E, [2017-05-18T05:57:47.221238 #9371:b0d13c] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) EMS: [istein-rhv], id: [1] Unable to perform refresh for the following targets:
[----] E, [2017-05-18T05:57:47.221407 #9371:b0d13c] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh)  --- ManageIQ::Providers::Redhat::InfraManager [istein-rhv] id [1]
[----] I, [2017-05-18T05:57:47.243917 #9371:b0d13c]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Refresh::Strategies::Api3#refresh) Refreshing all targets...Complete
[----] E, [2017-05-18T05:57:47.244360 #9371:b0d13c] ERROR -- : MIQ(MiqQueue#deliver) Message id: [29382], Error: [version 3 of the api is not supported by the provider]
[----] E, [2017-05-18T05:57:47.244695 #9371:b0d13c] ERROR -- : [EmsRefresh::Refreshers::EmsRefresherMixin::PartialRefreshError]: version 3 of the api is not supported by the provider  Method:[rescue in deliver]
[----] E, [2017-05-18T05:57:47.245085 #9371:b0d13c] ERROR -- : /var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:50:in `refresh'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:9:in `refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:98:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:97:in `each'
/var/www/miq/vmdb/app/models/ems_refresh.rb:97:in `refresh'
/var/www/miq/vmdb/app/models/miq_queue.rb:347:in `block in deliver'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:91:in `block in timeout'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `block in catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:106:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `deliver'
Comment 3 Radim Hrazdil 2017-11-27 15:55:36 UTC 
Verified that after powering RHV provider off, relevant message is displayer in refresh summary (Can't send request: Timeout was reached). 

Version 5.9.0.10