Bug 1450644

Summary: Enabling Capacity & Utilization without filling C&U credentials generate repeated Errors in evm.log
Product: Red Hat CloudForms Management Engine Reporter: Ilanit Stein <istein>
Component: ProvidersAssignee: Boriso <bodnopoz>
Status: CLOSED CURRENTRELEASE QA Contact: Angelina Vasileva <anikifor>
Severity: medium Docs Contact:
Priority: medium    
Version: 5.8.0CC: istein, jfrey, jhardy, jzmeskal, mgoldboi, obarenbo
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:
: 1478421 (view as bug list) Environment:
Last Closed: 2018-03-06 14:46:41 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: 1478421    
Attachments:
Description Flags
evm.log none

Description Ilanit Stein 2017-05-14 10:57:00 UTC
Description of problem:
CFME Enabling Capacity & Utilization by Configuration->Turn those flags ON: 
- automation Engine 
- Capacity & Utilization Coordinator 
- Capacity & Utilization Data Collector 
If the RHV provider C&U credentials are not filled,
a repeated unhanded exception appear in evm.log

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

How reproducible:
100%

Expected results:
There shouldn't be an unhanded exception in such case.
It can maybe replaced with some warning, saying C&U credentials are required, in order to perform the C&U data collection.

Error in evm.log:
[----] I, [2017-05-14T06:12:33.582038 #46600:6c9134]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::MetricsCollectorWorker::Runner#get_message_via_drb) Message id: [103026], MiqWorker id: [114], Zone: [default], Role: [ems_metrics_collector], Server: [], Ident: [redhat], Target id: [], Instance id: [4], Task id: [], Command: [ManageIQ::Providers::Redhat::InfraManager::Host.perf_capture_realtime], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [2017-05-14 00:00:00 UTC], Dequeued in: [9.157821902] seconds
[----] I, [2017-05-14T06:12:33.582229 #46600:6c9134]  INFO -- : MIQ(MiqQueue#deliver) Message id: [103026], Delivering...
[----] I, [2017-05-14T06:12:33.584950 #46600:6c9134]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Host#perf_capture) [realtime] Capture for ManageIQ::Providers::Redhat::InfraManager::Host name: [host_mixed_1], id: [4], start_time: [2017-05-14 00:00:00 UTC]...
[----] E, [2017-05-14T06:12:33.592554 #46600:6c9134] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::MetricsCapture#perf_collect_metrics) [realtime] for: [ManageIQ::Providers::Redhat::InfraManager::Host], [4], [host_mixed_1] Unhandled exception during perf data collection: [no metrics credentials defined], class: [RuntimeError]
[----] E, [2017-05-14T06:12:33.592681 #46600:6c9134] ERROR -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::MetricsCapture#perf_collect_metrics) [realtime] for: [ManageIQ::Providers::Redhat::InfraManager::Host], [4], [host_mixed_1]   Timings at time of error: {:server_dequeue=>0.0035161972045898438, :capture_state=>25.744176864624023, :rhevm_connect=>23.8639817237854, :total_time=>118.08352899551392, :db_find_storage_files=>1.3814702033996582, :init_attrs=>2.0514702796936035, :db_find_prev_perfs=>1.130441665649414, :process_perfs=>44.3594012260437, :process_perfs_tag=>0.12806034088134766, :process_bottleneck=>10.01521611213684}
[----] E, [2017-05-14T06:12:33.592916 #46600:6c9134] ERROR -- : [RuntimeError]: no metrics credentials defined  Method:[rescue in perf_collect_metrics]
[----] E, [2017-05-14T06:12:33.593179 #46600:6c9134] ERROR -- : /var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/metrics_capture.rb:7:in `perf_init_rhevm'
/var/www/miq/vmdb/app/models/manageiq/providers/redhat/infra_manager/metrics_capture.rb:39:in `block in perf_collect_metrics'
/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/manageiq/providers/redhat/infra_manager/metrics_capture.rb:39:in `perf_collect_metrics'
/var/www/miq/vmdb/app/models/metric/ci_mixin/capture.rb:6:in `perf_collect_metrics'
/var/www/miq/vmdb/app/models/metric/ci_mixin/capture.rb:180:in `block in perf_capture'
/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/metric/ci_mixin/capture.rb:177:in `perf_capture'
/var/www/miq/vmdb/app/models/metric/ci_mixin/capture.rb:117:in `perf_capture_realtime'
/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/miq_worker.rb:150:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:150: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'

Comment 2 Ilanit Stein 2017-05-14 11:00:33 UTC
Created attachment 1278617 [details]
evm.log

Comment 5 Jan Zmeskal 2017-11-10 09:39:36 UTC
@Ilanit: When I reproduced your steps from the first time, I found significant amount of warnings in evm.log. (See the attachment) In subsequent attempts to do the same, there were no warnings any more. 
However during the first time, the warning was "Garbage collection took 27.952864933991805 seconds" and then it seems like some dump of information. It is not clear from the warnings that credentials are missing. Therefore I do not believe this is the expected behaviour. What do you think?

Comment 7 Ilanit Stein 2017-11-15 15:54:00 UTC
In reply to comment 5:

Jan,
I tend to agree.

Un handled exception no longer appear, but instead, there are many warnings,
and no clear message, indicating credentials are missing.

Thus moving bug back to assigned.

Comment 8 Boriso 2017-11-19 09:20:51 UTC
Can you please verify this?
The errors of garbage collection has nothing to do with this bug.

Comment 9 Ilanit Stein 2017-11-19 09:37:18 UTC
After rethinking on this:
The main purpose of this bug was to remove the unhandled exception seen in evm.log,
and this was indeed removed.
The fact that there was no warning added in evm.log, that credentials are missing, on order to perform the C&U collection, seems to me less critical.

Moving bug to Verified.