Description of problem: I have been monitoring my environment and am getting many occurrences of this error daily on evm.log: [----] I, [2016-11-21T09:17:12.099144 #32362:53f994] INFO -- : MIQ(MiqQueue#deliver) Message id: [10000070272161], Delivering... [----] E, [2016-11-21T09:17:12.102554 #32362:53f994] ERROR -- : MIQ(MiqQueue#deliver) Message id: [10000070272161], Error: [Couldn't find MiqTask with 'id'=10000000137883] [----] E, [2016-11-21T09:17:12.102822 #32362:53f994] ERROR -- : [ActiveRecord::RecordNotFound]: Couldn't find MiqTask with 'id'=10000000137883 Method:[rescue in deliver] [----] E, [2016-11-21T09:17:12.103038 #32362:53f994] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation/finder_methods.rb:357:in `raise_record_not_found_exception!' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation/finder_methods.rb:477:in `find_one' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation/finder_methods.rb:456:in `find_with_ids' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation/finder_methods.rb:66:in `find' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation.rb:491:in `destroy' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation.rb:489:in `block in destroy' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation.rb:489:in `map' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/relation.rb:489:in `destroy' /opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/querying.rb:8:in `destroy' /var/www/miq/vmdb/app/models/miq_queue.rb:345:in `block in deliver' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:89:in `block in timeout' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `block in catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch' /opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:104:in `timeout' /var/www/miq/vmdb/app/models/miq_queue.rb:341:in `deliver' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:106:in `deliver_queue_message' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:134:in `deliver_message' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:152:in `block in do_work' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `loop' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `do_work' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:334:in `block in do_work_loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:331: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:128: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:347:in `block in start' /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:345:in `start' /var/www/miq/vmdb/app/models/miq_worker.rb:274: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:52: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:173:in `start' /var/www/miq/vmdb/app/models/miq_server.rb:265:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:92:in `start' /var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>' [----] I, [2016-11-21T09:17:12.103350 #32362:53f994] INFO -- : MIQ(MiqQueue#delivered) Message id: [10000070272161], State: [error], Delivered in [0.004209486] seconds Version-Release number of selected component (if applicable): 5.6.2.2.20161017185613_7cee0a0 How reproducible: Not sure. Actual results: See Exception Expected results: No error. Additional info: Environment credentials can be shared on request.
Created attachment 1222562 [details] evm.log with raise_record_not_found_exception errors
Nandini, can you try and reproduce this? Jerome was thinking maybe it as something to do with managing providers that do not support c&u when c&u is enabled.
I haven't been able to reproduce this issue. I tested an appliance managing SCVMM(SCVMM doesn't support C&U)with C&U enabled.
https://github.com/ManageIQ/manageiq/pull/15415
New commit detected on ManageIQ/manageiq/master: https://github.com/ManageIQ/manageiq/commit/ad3525f246832d90824b415c5b11e56187493f34 commit ad3525f246832d90824b415c5b11e56187493f34 Author: Yuri Rudman <yrudman> AuthorDate: Tue Jun 20 14:47:18 2017 -0400 Commit: Yuri Rudman <yrudman> CommitDate: Wed Jun 21 09:55:16 2017 -0400 no need to delete task records in 2 steps (get list of ID first and queue destroy for those id). If queue is busy then there are could be several request to delete task with the same id. Instead queue actual condition to filter record and execute destroy_all. https://bugzilla.redhat.com/show_bug.cgi?id=1397247 app/models/miq_task.rb | 15 ++++++++++++--- spec/models/miq_task_spec.rb | 21 +++++++++++++-------- 2 files changed, 25 insertions(+), 11 deletions(-)
*** Bug 1422601 has been marked as a duplicate of this bug. ***
Yuri, I'm working on reproducing this issue.Could you provide steps to reproduce this issue? Thanks, Nandini
To duplicate this error: there should be 2 request in the queue to delete tasks and some tasks(to delete) should be present in both requests. Steps: 1. Generate several reports 2. Stop EVM Server Processes 3. from rails console execute 2 commands: > MiqTask.delete_older(Time.now, "name LIKE 'Generate Report:%'") > MiqTask.delete_older(Time.now, "name LIKE 'Generate Report:%'") 4. Start EVM Server Processes
Verified in 5.9.0.20
Steps: 1. Disable Reporting role. 2. Queue several reports.Reporting role is disabled so that these reports remain queued and don't get run. 2. Stop EVM Server Processes 3. from rails console execute 2 commands: > MiqTask.delete_older(Time.now, "name LIKE 'Generate Report:%'") > MiqTask.delete_older(Time.now, "name LIKE 'Generate Report:%'") 'evmserver' is stopped so that these two 'delete' tasks remain queued and don't get run 4. Start EVM Server Processes Before fix: Error message in evm.log After fix: No error message in evm.log
This issue impact 58 as well. Can the fix be backported to 58?
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2018:0380