Bug 1638045

Summary: Metric capture tracebacks for Microsoft SCVMM provider
Product: Red Hat CloudForms Management Engine Reporter: Tasos Papaioannou <tpapaioa>
Component: C&U Capacity and UtilizationAssignee: Adam Grare <agrare>
Status: CLOSED CURRENTRELEASE QA Contact: Tasos Papaioannou <tpapaioa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 5.9.5CC: dmetzger, mfeifer, obarenbo, simaishi, smallamp, tpapaioa
Target Milestone: GA   
Target Release: 5.10.0   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 5.10.0.27 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-04-10 18:03:54 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: CFME Core Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1595696    

Description Tasos Papaioannou 2018-10-10 14:23:05 UTC 
Description of problem:

If C&U is enabled, a Microsoft provider will regularly trigger tracebacks in evm.log.

Version-Release number of selected component (if applicable):

Verified on 5.9.5 and 5.10.0. Not seen on 5.8.5.

How reproducible:

100%

Steps to Reproduce:
1.) Enable C&U server roles and collection for all clusters / datastores.
2.) Create a Microsoft System Center VMM provider.
3.) Monitor evm.log.

Actual results:

Regular tracebacks:

****
[----] I, [2018-10-09T11:04:15.457653 #12115:b3af74]  INFO -- : MIQ(MiqPriorityWorker::Runner#get_message_via_drb) Message id: [374], MiqWorker id: [15], Zone: [default], Role: [ems_metrics_coordinator], Server: [], MiqTask id: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Metric::Capture.perf_capture_timer], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.199154802] seconds
[----] I, [2018-10-09T11:04:15.457830 #12115:b3af74]  INFO -- : MIQ(MiqQueue#deliver) Message id: [374], Delivering...
[----] I, [2018-10-09T11:04:15.458126 #12115:b3af74]  INFO -- : MIQ(Metric::Capture.perf_capture_timer) Queueing performance capture...
[----] I, [2018-10-09T11:04:15.459992 #12115:b3af74]  INFO -- : MIQ(Metric::Capture.perf_capture_health_check) 0 "realtime" captures on the queue for zone [default]
[----] I, [2018-10-09T11:04:15.460108 #12115:b3af74]  INFO -- : MIQ(Metric::Capture.perf_capture_health_check) 0 "hourly" captures on the queue for zone [default]
[----] I, [2018-10-09T11:04:15.460184 #12115:b3af74]  INFO -- : MIQ(Metric::Capture.perf_capture_health_check) 0 "historical" captures on the queue for zone [default]
[----] E, [2018-10-09T11:04:15.495573 #12115:b3af74] ERROR -- : [NameError]: uninitialized constant ManageIQ::Providers::Microsoft::InfraManager::MetricsCapture  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2018-10-09T11:04:15.495929 #12115:b3af74] ERROR -- : /var/www/miq/vmdb/app/models/metric/ci_mixin.rb:24:in `block (2 levels) in <module:CiMixin>'
/var/www/miq/vmdb/app/models/mixins/supports_feature_mixin.rb:261:in `instance_eval'
/var/www/miq/vmdb/app/models/mixins/supports_feature_mixin.rb:261:in `block in define_supports_feature_methods'
/var/www/miq/vmdb/app/models/metric/targets.rb:27:in `block in only_enabled'
/var/www/miq/vmdb/app/models/metric/targets.rb:26:in `select'
/var/www/miq/vmdb/app/models/metric/targets.rb:26:in `only_enabled'
/var/www/miq/vmdb/app/models/metric/targets.rb:14:in `capture_infra_targets'
/var/www/miq/vmdb/app/models/metric/targets.rb:144:in `capture_targets'
/var/www/miq/vmdb/app/models/metric/capture.rb:51:in `perf_capture_timer'
/var/www/miq/vmdb/app/models/miq_queue.rb:455:in `block in dispatch_method'
/usr/share/ruby/timeout.rb:93:in `block in timeout'
/usr/share/ruby/timeout.rb:33:in `block in catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:108:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:453:in `dispatch_method'
/var/www/miq/vmdb/app/models/miq_queue.rb:430:in `block in deliver'
/var/www/miq/vmdb/app/models/user.rb:267:in `with_user_group'
/var/www/miq/vmdb/app/models/miq_queue.rb:430:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:104:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:137:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:155:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:329:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:127:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:22:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:402:in `block in start_runner_via_fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:400:in `start_runner_via_fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:390:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:441:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:271:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:154: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.rb:148:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:240:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:27:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:48:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'

[...]

[----] I, [2018-10-09T11:04:15.515239 #12115:b3af74]  INFO -- : MIQ(MiqTask.delete_older) Queuing deletion of tasks older than 2018-10-09 11:04:15 UTC and with condition: name LIKE 'Performance rollup for %'
[----] I, [2018-10-09T11:04:15.533187 #12115:b3af74]  INFO -- : MIQ(MiqQueue.put) Message id: [375],  id: [], Zone: [default], Role: [], Server: [], MiqTask id: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqTask.destroy_older_by_condition], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [2018-10-09 11:04:15 UTC, "name LIKE 'Performance rollup for %'"]
[----] I, [2018-10-09T11:04:15.533490 #12115:b3af74]  INFO -- : MIQ(Metric::Capture.perf_capture_timer) Queueing performance capture...Complete
[----] I, [2018-10-09T11:04:15.534049 #12115:b3af74]  INFO -- : MIQ(MiqQueue#delivered) Message id: [374], State: [ok], Delivered in [0.076195731] seconds
****


Expected results:

No tracebacks.

Additional info:
Comment 2 dmetzger 2018-10-11 13:53:28 UTC 
Please test with 5.9.4 and report results here.
Comment 3 Tasos Papaioannou 2018-10-11 15:02:21 UTC 
I tested and can see the same issue on 5.9.4, 5.9.3, and 5.9.2.
Comment 4 Tasos Papaioannou 2018-10-11 16:02:29 UTC 
Also tested and verified the same issue on 5.9.1 and 5.9 GA.
Comment 5 CFME Bot 2018-11-26 18:00:55 UTC 
https://github.com/ManageIQ/manageiq/pull/18233
Comment 6 CFME Bot 2018-11-26 19:00:53 UTC 
New commit detected on ManageIQ/manageiq/master:

https://github.com/ManageIQ/manageiq/commit/6e33bbe60eb27d03eb1c2aa748ada74b7daed1a8
commit 6e33bbe60eb27d03eb1c2aa748ada74b7daed1a8
Author:     Adam Grare <agrare>
AuthorDate: Mon Nov 26 12:52:19 2018 -0500
Commit:     Adam Grare <agrare>
CommitDate: Mon Nov 26 12:52:19 2018 -0500

    Fix supports_capture assuming MetricsCapture class

    The supports :capture block assumes that the MetricsCapture class always
    exists even if metrics capture is unsupported which is not the case.

    Modify the block to check for the existence of the metrics capture class
    before checking its instance methods.

    Also fix the unsupported_reason_add setting the reason to the wrong
    feature key (:metrics when should have been :capture).

    Fixes https://bugzilla.redhat.com/show_bug.cgi?id=1638045

 app/models/metric/ci_mixin.rb | 5 +-
 spec/models/metric/ci_mixin_spec.rb | 22 +
 2 files changed, 25 insertions(+), 2 deletions(-)
Comment 7 CFME Bot 2018-11-27 21:56:31 UTC 
New commit detected on ManageIQ/manageiq/hammer:

https://github.com/ManageIQ/manageiq/commit/43ed8cb994eb57ae7f71eb0f3da0483660bc2c65
commit 43ed8cb994eb57ae7f71eb0f3da0483660bc2c65
Author:     Keenan Brock <keenan>
AuthorDate: Mon Nov 26 13:54:42 2018 -0500
Commit:     Keenan Brock <keenan>
CommitDate: Mon Nov 26 13:54:42 2018 -0500

    Merge pull request #18233 from agrare/bz_1638045_fix_supports_capture

    Fix supports_capture assuming MetricsCapture class

    (cherry picked from commit 603d59a07d00289e03c0936f371145b2abe725d4)

    Fixes https://bugzilla.redhat.com/show_bug.cgi?id=1638045

 app/models/metric/ci_mixin.rb | 5 +-
 spec/models/metric/ci_mixin_spec.rb | 22 +
 2 files changed, 25 insertions(+), 2 deletions(-)
Comment 9 Tasos Papaioannou 2019-04-10 17:07:37 UTC 
Verified on 5.10.0.33 and 5.10.3.0.