Search code examples
ruby-on-rails-4unicornrufus-scheduler

rufus-scheduler not scheduling when running on top of Rails+Unicorn in detached mode


I am using rufus-scheduler to schedule some jobs in my Ruby on Rails application. Relevant specs:

  • Ruby: 2.1.2p95
  • Rails: 4.1.1
  • Rufus-Scheduler: 3.0.9

The scheduler runs perfectly fine when I run the application using "rails s unicorn". However when I detach the server using the "-d" option, the scheduled jobs never run.

Here is my config/initializers/task_scheduler.rb file:

require 'rubygems'
require 'rufus/scheduler'
require 'rake'

load File.join(Rails.root, 'lib', 'tasks', 'send_emails.rake')
MyApplication::Application.load_tasks
scheduler = Rufus::Scheduler.new(:lockfile => ".rufus-scheduler.lock")

if (!MyApplication.rake?)
  unless scheduler.down?

    Rails.logger.info "OK"

    scheduler.interval("1m") do
      Rails.logger.info "yup"
      system ("rake send_emails:mail_users")
    end 

  end
end

and my unicorn.rb file:

worker_processes 2
preload_app true
timeout 30

before_fork do |server, worker|
  Signal.trap 'TERM' do
    puts 'Unicorn master intercepting TERM and sending myself QUIT instead'
    Process.kill 'QUIT', Process.pid
  end

  defined?(ActiveRecord::Base) and
    ActiveRecord::Base.connection.disconnect!
end

after_fork do |server, worker|
  Signal.trap 'TERM' do
    puts 'Unicorn worker intercepting TERM and doing nothing. Wait for master to send QUIT'
  end

  defined?(ActiveRecord::Base) and
    ActiveRecord::Base.establish_connection
end

The "!MyApplication.rake?" line is to prevent rake tasks from running the scheduler as well; I've added this line to my Rakefile:

MyApplication.rake = true

When I look at my log I notice that the "OK" line is being printed, so I believe the scheduler is initializing properly, but the logger line for the job is never printed and the rake task doesn't run.

At this point I'm unsure whether the problem lies in my unicorn configuration, or my scheduler configuration. Any help would be greatly appreciated!

edit 1:

Log output from "rails s"

I, [2015-01-28T20:11:05.179505 #79141]  INFO -- : listening on addr=0.0.0.0:3000 fd=12
Before
Before
I, [2015-01-28T20:11:05.426386 #79141]  INFO -- : master process ready
After
After
I, [2015-01-28T20:11:05.434392 #79143]  INFO -- : worker=0 ready
I, [2015-01-28T20:11:05.435585 #79144]  INFO -- : worker=1 ready
yup

Log output from "rails s -d"

OK
Before
Before
After
After

As jmettraux suggested, the scheduler appears to be getting lost after the fork when using the "-d" option. I switched things up a bit a moved the scheduler into a class and called the initializer from the after_fork block:

lib/scheduler.rb

require 'rufus/scheduler'
class Scheduler

  def self.startup
    Rails.logger.info "startup"
    load File.join(Rails.root, 'lib', 'tasks', 'send_emails.rake')
    USA::Application.load_tasks
    scheduler = Rufus::Scheduler.new(:lockfile => ".rufus-scheduler.lock")

    if (!USA.rake?)
      Rails.logger.info "nope"
      unless scheduler.down?
        Rails.logger.info "OK"

        scheduler.interval("1m") do
          Rails.logger.info "yup"
          system ("rake send_emails:mail_users")
        end

        scheduler.join

      end
    end
  end

end

unicorn.rb:

worker_processes 2
preload_app true
timeout 100

load File.join(Rails.root, 'lib', 'scheduler.rb')

...

after_fork do |server, worker|
  Rails.logger.info "After"
  Signal.trap 'TERM' do
    puts 'Unicorn worker intercepting TERM and doing nothing. Wait for master to send QUIT'
  end

  defined?(ActiveRecord::Base) and
    ActiveRecord::Base.establish_connection

  Scheduler::startup

end

However, this spins out of control when launching "rails s -d" and the workers are constantly being spawned and killed:

Before
Before
After
After
startup
startup
Before
After
Before
startup
After
startup
Before
After
startup

I'm sure my implementation of starting the scheduler from the after_fork block is probably to blame, but I'm not sure exactly what is causing this.

edit 2

I'm stupid. I was using the gist that jmettraux linked, but I butchered it when I was trying to get it to work in my application. I went back and started both my unicorn.rb and scheduler.rb from scratch and it's working now!


Solution

  • You should add some Rails.logger.info("XXX") in the after_fork block to see if it happens before the OK or after it.

    It seems someone had the same issue and came up with something: https://gist.github.com/jkraemer/3851917 It's four years old, but it could give you some inspiration.

    The "gist" of it seems to be to run/start rufus-scheduler in the after_fork block (so that its thread doesn't get killed in the fork).