Bug 1279601 - dozens of "[RuntimeError]: Expected scheduled time 'at' to be 'numeric', received 'Time' Method:[rescue in deliver]" associated with specific default reports
dozens of "[RuntimeError]: Expected scheduled time 'at' to be 'numeric', rece...
Status: CLOSED ERRATA
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Reporting (Show other bugs)
5.5.0
x86_64 Linux
high Severity medium
: GA
: 5.5.0
Assigned To: Tim Wade
Milan Falešník
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-11-09 15:21 EST by Thomas Hennessy
Modified: 2015-12-08 08:45 EST (History)
6 users (show)

See Also:
Fixed In Version: 5.5.0.11
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-12-08 08:45:48 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Thomas Hennessy 2015-11-09 15:21:15 EST
Description of problem:error apparently generated after some scheduled reports are being rescheduled for future execution


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

How reproducible: Create hourly schedule for "VM disk Usage" report


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Full error sequence from message initiating report to end of message processing:
=====
[----] I, [2015-11-06T11:00:23.084261 #2886:f6d998]  INFO -- : MIQ(MiqReportingWorker::Runner#get_message_via_drb) Message id: [441000000007735], MiqWorker id: [441000000000021], Zone: [], Role: [reporting], Server: [], Ident: [reporting], Target id: [], Instance id: [441000000000004], Task id: [], Command: [MiqReport.build_report_result], Timeout: [3600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [441000000000014, {:send_email=>false, :userid=>"admin"}, {:at=>2015-11-06 15:00:00 -0500, :source=>"Scheduled"}], Dequeued in: [5.895468075] seconds
[----] I, [2015-11-06T11:00:23.445481 #2886:f6d998]  INFO -- : MIQ(MiqReport#build_report_result) Generating report table with taskid [441000000000014] and options [{:send_email=>false, :userid=>"admin"}]
[----] I, [2015-11-06T11:00:23.449824 #2886:f6d998]  INFO -- : MIQ(MiqTask#update_status) Task: [441000000000014] [Active] [Ok] [Generating report]
[----] I, [2015-11-06T11:00:23.903058 #2886:f6d998]  INFO -- : MIQ(MiqReport#build_create_results) Creating report results with hash: [{:name=>"VM Disk Usage", :userid=>"admin", :report_source=>"Scheduled", :db=>"VmPerformance", :last_run_on=>2015-11-06 16:00:23 UTC, :last_accessed_on=>2015-11-06 16:00:23 UTC, :miq_report_id=>441000000000004}]
[----] I, [2015-11-06T11:00:24.282505 #2886:f6d998]  INFO -- : MIQ(MiqReport#build_create_results) Finished creating report result with id [441000000000001] for report id: [441000000000004], name: [VM Disk Usage]
[----] I, [2015-11-06T11:00:24.369273 #2886:f6d998]  INFO -- : MIQ(MiqTask#update_status) Task: [441000000000014] [Finished] [Ok] [Generating report complete]
[----] I, [2015-11-06T11:00:24.399094 #2886:f6d998]  INFO -- : MIQ(MiqReport#build_report_result) Generating report table with taskid [441000000000014]... Complete
[----] E, [2015-11-06T11:00:24.399768 #2886:f6d998] ERROR -- : MIQ(MiqQueue#deliver) Message id: [441000000007735], Error: [Expected scheduled time 'at' to be 'numeric', received 'Time']
[----] E, [2015-11-06T11:00:24.400072 #2886:f6d998] ERROR -- : [RuntimeError]: Expected scheduled time 'at' to be 'numeric', received 'Time'  Method:[rescue in deliver]
[----] E, [2015-11-06T11:00:24.400244 #2886:f6d998] ERROR -- : /var/www/miq/vmdb/app/models/miq_report/generator.rb:771:in `build_report_result'
/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:151:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:145:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:145:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:323:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:320:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:320:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:142:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:123:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:24:in `start_worker'
/var/www/miq/vmdb/lib/workers/bin/worker.rb:2:in `<top (required)>'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/runner.rb:60:in `load'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/runner.rb:60:in `<top (required)>'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/commands_tasks.rb:123:in `require'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/commands_tasks.rb:123:in `require_command!'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/commands_tasks.rb:90:in `runner'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
/opt/rh/cfme-gemset/bundler/gems/rails-a37d0e57571f/railties/lib/rails/commands.rb:17:in `<top (required)>'
/var/www/miq/vmdb/bin/rails:4:in `require'
/var/www/miq/vmdb/bin/rails:4:in `<main>'
[----] I, [2015-11-06T11:00:24.400603 #2886:f6d998]  INFO -- : MIQ(MiqQueue#delivered) Message id: [441000000007735], State: [error], Delivered in [1.315867487] seconds

=====
Comment 2 Tim Wade 2015-11-10 18:14:12 EST
PR: https://github.com/ManageIQ/manageiq/pull/5379
Comment 4 Milan Falešník 2015-11-19 07:49:28 EST
Verified in 5.5.0.11 against 5.5.0.9, both identically set, 5.5.0.9 spat the error message, 5.5.0.11 did not. \o/
Comment 6 errata-xmlrpc 2015-12-08 08:45:48 EST
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-2015:2551

Note You need to log in before you can comment on or make changes to this bug.