bug? rufus-scheduler#find_jobs and #[all|at|cron|every|pending]_job_count return unexpected values

[KJ]

Hi John,

I have an application where I pass in the job_ids (the id's from an
ActiveRecord 'events' table). I sometimes need to recreate the
complete schedule. I do this by unscheduling all existing jobs and
scheduling them again immediately. When I call 'find_jobs' afterwards
it sometimes returns fewer jobs than the jobs I scheduled (sometimes
0!). Also the jobs_counts of the various types are wrong.

I've included a test program to show the problem. It has three modes
MODE = [:at|:cron|:every]. Run like this:

ruby test.rb cron
ruby test.rb at
ruby test.rb every

* Running the code with MODE=:cron produces the expected results.

Output (as expected):
cron: 30s from now
all:1000 at:0 cron:1000 every:0 pending:0
all:1000 at:0 cron:1000 every:0 pending:0
all:1000 at:0 cron:1000 every:0 pending:0

* Running the code with MODE=:at triggers the jobs correctly but the
jobs aren't returned by find_jobs or reported in the at_job_count.

Output:
at: 30s from now
all:1000 at:1000 cron:0 every:0 pending:0
all:0 at:0 cron:0 every:0 pending:1000
all:0 at:0 cron:0 every:0 pending:1000

I would expect:
all:1000 at:1000 cron:0 every:0 pending:1000

* Running the code with MODE=:every doesn't trigger the jobs and shows
unexpected values for find_jobs and [all|at|cron|every|pending]
_job_count

Output:
every: 30s from now
all:1000 at:0 cron:0 every:1000 pending:593
all:1000 at:0 cron:0 every:1000 pending:1000
all:0 at:0 cron:0 every:0 pending:0
all:0 at:0 cron:0 every:0 pending:0
all:0 at:0 cron:0 every:0 pending:0

I would expect:
all:1000 at:0 cron:0 every:1000 pending:1000

Can you tell me if this is a bug or am I doing something wrong?

Regards,

KJ

p.s. The test code is a bit long, but it tests various scenarios.

------ %<------

#!/usr/bin/env ruby

require 'rubygems'
require 'rufus/scheduler'

#
# Test program for rufus-scheduler
#
# Run like this:
# test.rb at
# test.rb every
# test.rb cron
#

SECONDS_FROM_NOW = 30
MODE = ([:at, :every, :cron].include?(ARGV[0].to_sym) ? ARGV
[0].to_sym : :cron)
JOB_COUNT = 1000
JOB_IDS = (1..JOB_COUNT).to_a
NUM_RESCHEDULES = 10

case MODE
when :at
AT_TRIGGER = Time.now + SECONDS_FROM_NOW # 30 seconds from now
when :every
EVERY_TRIGGER = "#{SECONDS_FROM_NOW}s" # after 30 seconds
when :cron
CRON_TRIGGER = ((Time.now.to_i%60) + SECONDS_FROM_NOW) % 60 # 30
seconds from now
end
puts "#{MODE.to_s}: #{SECONDS_FROM_NOW}s from now"

@trigger_queue = Queue.new

def schedule_jobs(scheduler)
trigger_proc = lambda { |params|
# print "#{params[:job_id]}, "
@trigger_queue << params[:job_id]
}
JOB_IDS.each do |job_id|
case MODE
when :at
scheduler.at(AT_TRIGGER, {:job_id => job_id}, &trigger_proc)
when :every
scheduler.every(EVERY_TRIGGER, {:job_id => job_id},
&trigger_proc)
when :cron
scheduler.cron("%d * * * * *" % CRON_TRIGGER,
{:job_id => job_id}, &trigger_proc)
end
end
end

def unschedule_jobs(scheduler)
JOB_IDS.each { |job_id| scheduler.unschedule(job_id) }
end

scheduler = Rufus::Scheduler.start_new

# Schedule all jobs, then unschedule and (re)schedule a number of
times
schedule_jobs(scheduler)
1.upto(NUM_RESCHEDULES) do

unschedule_jobs(scheduler)
schedule_jobs(scheduler)
end

# give scheduler thread 10 seconds to process the schedule and
unschedule requests
# but don't wait for the jobs to trigger (which is in less than 60
seconds)
1.upto(10) do
puts "all:%d at:%d cron:%d every:%d pending:%d" % [
scheduler.all_jobs.size,
scheduler.at_job_count,
scheduler.cron_job_count,
scheduler.every_job_count,
scheduler.pending_job_count]
sleep 1
end

# by now the scheduler should have processes everything, check
test_result = nil
if JOB_IDS.sort == scheduler.find_jobs.map{ |job| job.job_id }.sort
puts test_result = "PASS"
else
puts test_result = "FAIL: find_jobs does not return all jobs"
end

wait = 30
puts "Waiting #{wait} seconds for jobs to trigger"
sleep wait # wait for jobs to trigger
puts "\nTriggered #{@trigger_queue.size} jobs, should be (#
{JOB_COUNT})"
puts test_result

[John Mettraux]

On Fri, May 1, 2009 at 12:06 AM, KJ <k.j.wi...@gmail.com> wrote:
>
> I have an application where I pass in the job_ids (the id's from an
> ActiveRecord 'events' table). I sometimes need to recreate the
> complete schedule. I do this by unscheduling all existing jobs and
> scheduling them again immediately. When I call 'find_jobs' afterwards
> it sometimes returns fewer jobs than the jobs I scheduled (sometimes
> 0!). Also the jobs_counts of the various types are wrong.
>
> I've included a test program to show the problem.
>

> (...)

>
> Can you tell me if this is a bug or am I doing something wrong?

Hi Klaas,

it's definitely a bug, thanks for the detailed report.

I could reproduce it for rufus-scheduler.

I also integrated your test with the next version of rufus-scheduler :

http://github.com/jmettraux/rufus-scheduler-em/
http://github.com/jmettraux/rufus-scheduler-em/blob/master/test/kjw.rb

The next rufus-scheduler works like the current one, but it has an
EventMachine mode that some may find handy. It passes your test.

This next rufus-scheduler doesn't yet reproduce all the functionality
of the current one, missing are : job timeout, :first_at, :first_in
and :dont_reschedule. I will push it out in the wild during the coming
weeks.

Meanwhile I will try to fix the issue you've exposed for the current-scheduler.

Thanks again,

--
John Mettraux - http://jmettraux.wordpress.com

[John Mettraux]

On Fri, May 1, 2009 at 12:45 PM, John Mettraux <jmet...@openwfe.org> wrote:
> On Fri, May 1, 2009 at 12:06 AM, KJ <k.j.wi...@gmail.com> wrote:
>
> I also integrated your test with the next version of rufus-scheduler :
>
>  http://github.com/jmettraux/rufus-scheduler-em/
>  http://github.com/jmettraux/rufus-scheduler-em/blob/master/test/kjw.rb

Actually, I just moved rufus-scheduler-em to a
http://github.com/jmettraux/rufus-scheduler/tree/twozero branch that
should become 'master' soon.

The 1.0 branch was mostly written 3 years ago, I was very novice in
Ruby. This new branch is simpler.

Best regards,

[John Mettraux]

Hi Klaas Jan,

thanks a lot for the fix on master and the spec for twozero.

I have adapted that stress spec to bacon. Currently it fails for me
for every "at" tests. I will try to investigate that, maybe I will try
to isolate the spec into a shorter spec (your spec takes 11 minutes to
run, so I have not included it in the default spec suite run).

Thanks for the excellent work !

[Klaas Jan Wierenga]

John,

I've fixed the spec. Please see my pull request.

Regards,
KJ

[John Mettraux]

On Sun, May 3, 2009 at 7:24 AM, Klaas Jan Wierenga
<k.j.wi...@gmail.com> wrote:
>
> John,
>
> I've fixed the spec. Please see my pull request.

Thanks a lot, passes like a charm,

I've modified your spec so that it follows the presence/absence of the
--em command line option (via spec_base.rb) :

ruby spec/spec.rb [--em]

http://github.com/jmettraux/rufus-scheduler/commit/806234090068121f6583cfcb32cae72f1d39ebcd

Thanks again !