Supervisor spawns too many [program:x] #86

Closed
didip opened this Issue Feb 1, 2012 · 7 comments

Comments

3 participants
@didip

didip commented Feb 1, 2012

Supervisor config:

[program:resque-scheduler]
startsecs=6
command=/opt/ruby-enterprise/bin/rake resque:scheduler
environment=RAILS_ENV=production
directory=/path/to/app/current
user=app_user
stderr_logfile = /var/log/supervisor/resque-scheduler.log
stdout_logfile = /var/log/supervisor/resque-scheduler.log

This is a typical Rails app, it took seconds to boot. That's why I use startsecs option.

There should only be 1 of this program running. But every time I restarted supervisord (/etc/init.d/supervisord restart), it spawned two of this rake resque:scheduler.

Are there any options I can use to make sure only 1 instance of program:x running?

@theduderog

This comment has been minimized.

Show comment
Hide comment
@theduderog

theduderog Feb 1, 2012

Member

This is probably unrelated to supervisor. I'm guessing that if you run it
on the command line, it's also spawns two process: rake is the master and
it forks a child process that is the rails app.

Maybe you can try setting process.daemonize = false?

On Wed, Feb 1, 2012 at 10:57 AM, Didip Kerabat <
reply@reply.github.com

wrote:

Supervisor config:

[program:resque-scheduler]
startsecs=6
command=/opt/ruby-enterprise/bin/rake resque:scheduler
environment=RAILS_ENV=production
directory=/path/to/app/current
user=app_user
stderr_logfile = /var/log/supervisor/resque-scheduler.log
stdout_logfile = /var/log/supervisor/resque-scheduler.log

This is a typical Rails app, it took seconds to boot. That's why I use
startsecs option.

There should only be 1 of this program running. But every time I restarted
supervisord (/etc/init.d/supervisord restart), it spawned two of this rake
resque:scheduler.

Got any pointer why?


Reply to this email directly or view it on GitHub:
#86

Member

theduderog commented Feb 1, 2012

This is probably unrelated to supervisor. I'm guessing that if you run it
on the command line, it's also spawns two process: rake is the master and
it forks a child process that is the rails app.

Maybe you can try setting process.daemonize = false?

On Wed, Feb 1, 2012 at 10:57 AM, Didip Kerabat <
reply@reply.github.com

wrote:

Supervisor config:

[program:resque-scheduler]
startsecs=6
command=/opt/ruby-enterprise/bin/rake resque:scheduler
environment=RAILS_ENV=production
directory=/path/to/app/current
user=app_user
stderr_logfile = /var/log/supervisor/resque-scheduler.log
stdout_logfile = /var/log/supervisor/resque-scheduler.log

This is a typical Rails app, it took seconds to boot. That's why I use
startsecs option.

There should only be 1 of this program running. But every time I restarted
supervisord (/etc/init.d/supervisord restart), it spawned two of this rake
resque:scheduler.

Got any pointer why?


Reply to this email directly or view it on GitHub:
#86

@mnaberez

This comment has been minimized.

Show comment
Hide comment
@mnaberez

mnaberez Feb 1, 2012

Member

There should only be 1 of this program running. But every time I restarted supervisord
(/etc/init.d/supervisord restart), it spawned two of this rake resque:scheduler.

Supervisor spawned only one process but that process probably daemonized itself (see nondaemonizing of subprocessses). If so and you run rake resque:scheduler on your terminal, you will see it detach.

It looks like resque-scheduler was changed for 2.0.0.f to only daemonize when ENV['BACKGROUND'] is set. See the resque-scheduler changelog. That version does not appear to be released yet.

You could run the git version of resque-scheduler until that change is released. You could also try something like this in script/resque_scheduler and running it instead of rake resque:scheduler as a workaround:

#!/usr/bin/env ruby
require File.dirname(__FILE__) + '/../config/environment'

# unbuffered output
STDOUT.sync = true

# run forever
Resque::Scheduler.dynamic = false
Resque::Scheduler.verbose = true
Resque::Scheduler.run

That will run resque-scheduler without daemonizing the process.

Closing since this is not a Supervisor issue.

Edit: it looks like resque-scheduler versions before 2.0.0.f may not have daemonized. I still suspect it will run correctly using a script like the one above instead of through rake.

Member

mnaberez commented Feb 1, 2012

There should only be 1 of this program running. But every time I restarted supervisord
(/etc/init.d/supervisord restart), it spawned two of this rake resque:scheduler.

Supervisor spawned only one process but that process probably daemonized itself (see nondaemonizing of subprocessses). If so and you run rake resque:scheduler on your terminal, you will see it detach.

It looks like resque-scheduler was changed for 2.0.0.f to only daemonize when ENV['BACKGROUND'] is set. See the resque-scheduler changelog. That version does not appear to be released yet.

You could run the git version of resque-scheduler until that change is released. You could also try something like this in script/resque_scheduler and running it instead of rake resque:scheduler as a workaround:

#!/usr/bin/env ruby
require File.dirname(__FILE__) + '/../config/environment'

# unbuffered output
STDOUT.sync = true

# run forever
Resque::Scheduler.dynamic = false
Resque::Scheduler.verbose = true
Resque::Scheduler.run

That will run resque-scheduler without daemonizing the process.

Closing since this is not a Supervisor issue.

Edit: it looks like resque-scheduler versions before 2.0.0.f may not have daemonized. I still suspect it will run correctly using a script like the one above instead of through rake.

@mnaberez mnaberez closed this Feb 1, 2012

@didip

This comment has been minimized.

Show comment
Hide comment
@didip

didip Feb 1, 2012

@theduderog, unfortunately that is not the case. I didn't see any kind of forking happened when I ran it manually.

When looking at the source code of that rake task, it is just a method that registered signals and perform infinite loop.
See: https://github.com/bvandenbos/resque-scheduler/blob/master/lib/resque/scheduler.rb#L35

Maybe supervisor thought the first process didn't run (because it took a while to fire-up) and immediately spawn another process?

didip commented Feb 1, 2012

@theduderog, unfortunately that is not the case. I didn't see any kind of forking happened when I ran it manually.

When looking at the source code of that rake task, it is just a method that registered signals and perform infinite loop.
See: https://github.com/bvandenbos/resque-scheduler/blob/master/lib/resque/scheduler.rb#L35

Maybe supervisor thought the first process didn't run (because it took a while to fire-up) and immediately spawn another process?

@mnaberez mnaberez reopened this Feb 1, 2012

@mnaberez

This comment has been minimized.

Show comment
Hide comment
@mnaberez

mnaberez Feb 1, 2012

Member

When looking at the source code of that rake task, it is just a method that registered signals and perform infinite loop.

What version of resque-scheduler are you running?

Maybe supervisor thought the first process didn't run (because it took a while to fire-up) and immediately spawn another process?

If supervisord spawned another process, you should see this in its log.

Member

mnaberez commented Feb 1, 2012

When looking at the source code of that rake task, it is just a method that registered signals and perform infinite loop.

What version of resque-scheduler are you running?

Maybe supervisor thought the first process didn't run (because it took a while to fire-up) and immediately spawn another process?

If supervisord spawned another process, you should see this in its log.

@theduderog

This comment has been minimized.

Show comment
Hide comment
@theduderog

theduderog Feb 1, 2012

Member

i don't. just guessing.

On Wed, Feb 1, 2012 at 11:55 AM, Mike Naberezny <
reply@reply.github.com

wrote:

What version of resque-scheduler are you running?


Reply to this email directly or view it on GitHub:
#86 (comment)

Member

theduderog commented Feb 1, 2012

i don't. just guessing.

On Wed, Feb 1, 2012 at 11:55 AM, Mike Naberezny <
reply@reply.github.com

wrote:

What version of resque-scheduler are you running?


Reply to this email directly or view it on GitHub:
#86 (comment)

@didip

This comment has been minimized.

Show comment
Hide comment
@didip

didip Feb 1, 2012

@mnaberez

We do use gem 'resque-scheduler', '1.9.9'. But, when inspecting tasks.rb of that particular version, the daemonize code isn't there:

task :scheduler => :scheduler_setup do
  require 'resque'
  require 'resque_scheduler'

  Resque::Scheduler.verbose = true if ENV['VERBOSE']
  Resque::Scheduler.run
end

Resque::Scheduler.run simply registers signals and perform loop and I don't see any daemonizing happening inside. See:

def run

  # trap signals
  register_signal_handlers

  # Load the schedule into rufus
  load_schedule!

  # Now start the scheduling part of the loop.
  loop do
    handle_delayed_items
    poll_sleep
  end

  # never gets here.
end

didip commented Feb 1, 2012

@mnaberez

We do use gem 'resque-scheduler', '1.9.9'. But, when inspecting tasks.rb of that particular version, the daemonize code isn't there:

task :scheduler => :scheduler_setup do
  require 'resque'
  require 'resque_scheduler'

  Resque::Scheduler.verbose = true if ENV['VERBOSE']
  Resque::Scheduler.run
end

Resque::Scheduler.run simply registers signals and perform loop and I don't see any daemonizing happening inside. See:

def run

  # trap signals
  register_signal_handlers

  # Load the schedule into rufus
  load_schedule!

  # Now start the scheduling part of the loop.
  loop do
    handle_delayed_items
    poll_sleep
  end

  # never gets here.
end
@didip

This comment has been minimized.

Show comment
Hide comment
@didip

didip Feb 1, 2012

If supervisord spawned another process, you should see this in its log.

Correct. Inside /var/log/supervisord.log the whole situation is logged very clearly.

2012-01-30 17:55:35,659 INFO supervisord started with pid 32293
2012-01-30 17:55:36,674 INFO spawned: 'resque-scheduler' with pid 32311
2012-01-30 17:55:42,810 INFO success: resque-scheduler entered RUNNING state, process has stayed up for > than 6 seconds (startsecs)

It looks normal, there is no anomaly like unexpected killed.

This makes me think:
The problem is with shutdown method inside resque-scheduler, not supervisord.

trap("TERM") { shutdown }
trap("INT") { shutdown }

I think, for now, it's ok to close this issue.

didip commented Feb 1, 2012

If supervisord spawned another process, you should see this in its log.

Correct. Inside /var/log/supervisord.log the whole situation is logged very clearly.

2012-01-30 17:55:35,659 INFO supervisord started with pid 32293
2012-01-30 17:55:36,674 INFO spawned: 'resque-scheduler' with pid 32311
2012-01-30 17:55:42,810 INFO success: resque-scheduler entered RUNNING state, process has stayed up for > than 6 seconds (startsecs)

It looks normal, there is no anomaly like unexpected killed.

This makes me think:
The problem is with shutdown method inside resque-scheduler, not supervisord.

trap("TERM") { shutdown }
trap("INT") { shutdown }

I think, for now, it's ok to close this issue.

@didip didip closed this Feb 1, 2012

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment