Ideas and discussion about tracking behavior

While debugging something recently, I came up with two hacky methods to track the behavior of a scheduler. First I'll describe what I did and then discuss some ideas

In both cases I'm using line number to identify a job. The more thorough approach would have been to give each job a name, but I wanted to throw together something quickly for debugging purposes.

I had a problem where some jobs were taking a very long time and others weren't, and a related problem where one job was using up a lot more threads than others.

Let me know how interested you might be in PRs for either of these, and/or if you have ideas for how to implement in Rufus!

Hacks

report line number of job along with its duration to my stats tracker

# in on_post_trigger
# ...
line = job.handler.inspect.split[1].split(':')[1].delete_suffix('>') rescue 'ERROR'
StatTracker.value("Clock: Job #{line} Execution Time", duration.round(2))
# ...

report line number of which job is using which thread

schedule.every '5 seconds' do
  which_jobs = schedule.work_threads(:active).map do |t|
    t.backtrace.first.split.first.split(':')[1]
  end
  puts which_jobs.sort.join(', ')
end

Ideas

1. somehow associate job names with threads

If a name is given to a job, it would be great to be able to see which active threads in schedule.work_threads(:active) are being used by which job (is this somehow currently possible?).

2. An automatic name for each job

I'm using line numbers to identify jobs and it worked great for my purposes, but of course this is brittle because line numbers will change as the code changes. What if we had some other natural automatic name per job? For my purposes, in I think all cases, the first line of the job's lambda, stripped, would work perfectly. I haven't looked into how to access a Rufus job's block but here's a simple demo for methods, lambdas, and blocks:

require 'method_source'

class Thing
  def bar
    Hash.new
  end
end
puts Thing.new.method(:bar).source
# "  def bar\n    Hash.new\n  end\n"

l = lambda{
  puts "this is my lambda"
}
puts l.source
# l = lambda{
#   puts "this is my lambda"
# }


def takes_a_block(&block)
  puts block.source
end
takes_a_block do
  puts "this is the block i passed in"
end
# takes_a_block do
#   puts "this is the block i passed in"
# end

Job#name

rufus-scheduler/spec/job_spec.rb

Lines 389 to 397 in 64591be

    
           describe '#name' do 
        
             it 'returns the job name' do 
        
               j = @scheduler.schedule_in '10d', name: 'alice' do; end 
        
               expect(j.name).to eq('alice') 
        
             end 
        
           end

Hello,

I have the impression the hacks are better at the level of your ruby-clock gem.

Regarding the name, how about

class Rufus::Scheduler::Job
  def full_name
    [ name, source_location.map(&:to_s).join(':') ].join(' ')
  end
end

which returns something like "alice /home/jmettraux/w/rufus-scheduler/spec/job_spec.rb:408" ?

It uses the #source_location method I added to Job.

Best regards.

wow cool! thanks!

do you know if there's a way to access the job from schedule.work_threads(:active).first?

Hello,

yes, you can do

scheduler.work_threads(:active).each_with_index do |t, i|
  puts "#{i}. work thread #{t.id} is active for job #{t[:rufus_scheduler_job].source_location}"
end

Is that sufficient?

this is perfect - this code gives me exactly what i wanted

  job_code = schedule.work_threads(:active).map do |t|
    t[:rufus_scheduler_job].handler.source.split("\n")[1].strip
  end

OK, give me one or two days to release with Job#source_location, then I will close this issue.

Best regards.

Thanks, for now I don't need it for what I'm working on, so no time pressure here. I'll let you know what I come up with.

Okay, I've made Rufus::Scheduler::Job#identifier jjb/ruby-clock#2

I'm going to implement this at work first to see if I want to update anything, so it will get merged and released in the next few days. Any feedback welcome!

edit: I did actually end up depending on the new source_location feature!

just got a confusing error message from this code:

  schedule.work_threads(:active).each do |t|
    thread_usage[t[:rufus_scheduler_job].identifier] += 1
  end

undefined method `identifier' for true:TrueClass

it happened exactly once when my clock process started. Now that loop, which runs every 10 seconds, seems to be happy and functional.

Is there some kind of fallback scenario where that value might be true instead of the job instance?

Is there some kind of fallback scenario where that value might be true instead of the job instance?

Hello,

It's not a fallback, it's a temporary true value, to pre-reserve before assignation. IIRC.

https://github.com/jmettraux/rufus-scheduler/blob/master/lib/rufus/scheduler/jobs_core.rb#L311-L312

Gotcha, thanks! So it's only when the thread is starting up. so i think i can safely just next along when i see that and not risk losing any data

"losing data" sounds scary.

There is also the case where the thread use by the job just ended and it pops in your loop because when the .threads(:active) array was established it serviced a job, but when you consider it, it might have ended. I would do something like

  schedule.work_threads(:active).each do |t|
    i = t[:rufus_scheduler_job].identifier rescue nil
    thread_usage[i] += 1 if i
  end

That should cover the nil and the true extra cases.

3.8.0 released

Thanks!

great! and thanks for the extra info about missing jobs

	describe '#name' do

	it 'returns the job name' do

	j = @scheduler.schedule_in '10d', name: 'alice' do; end

	expect(j.name).to eq('alice')
	end
	end