[Backgroundrb-devel] Scheduled worker dies after about 30-45 runs

David Balatero david.balatero at gmail.com
Tue Mar 13 18:50:09 EDT 2007


I have a scheduled worker that runs every minute, checking for new eBay
auctions to post. If it finds an auction, then it posts it. If there are no
auctions in the database that are queued up, it simply does nothing. I got
the worker to finally run as a scheduled worker, every minute. However,
after about 30-45 scheduled runs, it simply stops running.

My backgroundrb_schedules.yml file:
------
ebay_runner:
  :class: :ebay_auction_worker
  :job_key: :ebay_auction_runner
  :trigger_type: :cron_trigger
  :trigger_args: 0 * * * * * *
------

My ebay_auction_worker.rb file:
------
class EbayAuctionWorker < BackgrounDRb::Rails
  # Set this worker to run every minute.
  attr_accessor :progress, :description

  def do_work(args)
    # This method is called in it's own new thread when you
    # call new worker. args is set to :args

    @progress = 0
    @description = "Checking for eBay auctions and posting"

    logger.info("Checking to post an auction at #{Time.now.to_s}.")
    auction = EbayAuction.find(:first, :conditions => ["auction_status = ?
AND post_on < ?", EbayAuction::STATUS_STRINGS[:queued], Time.now])
    if auction
      logger.info("--- Posting auction: #{auction.title}")

      # This method only takes 1-3 seconds tops to run -- it just generates
an <AddItem> call to eBay's XML API, and sends it along.
      auction.post
    else
      logger.info("--- No auctions currently need posting.")
    end

    @progress = 100

    logger.info("--- Finished auction check.")

    # Exit the thread to cleanup.
    self.delete
  end
end

EbayAuctionWorker.register
-------


>From the server logs, I'm getting this output:
--------
20070312-18:14:31 (24026) Starting BackgrounDRb Server
20070312-18:14:31 (24026) load_rails: true
20070312-18:14:31 (24026) uri:
drbunix:///tmp/backgroundrbunix_localhost_22222
20070312-18:14:31 (24026) config:
/home/david/redclay/config/backgroundrb.yml
20070312-18:14:31 (24026) temp_dir: /tmp
20070312-18:14:31 (24026) database_yml: config/database.yml
20070312-18:14:31 (24026) worker_dir: /home/david/redclay/lib/workers
20070312-18:14:31 (24026) protocol: drbunix
20070312-18:14:31 (24026) socket_dir: /tmp/backgroundrb.24026
20070312-18:14:31 (24026) environment: development
20070312-18:14:31 (24026) host: localhost
20070312-18:14:31 (24026) acl: denyallallowlocalhost 127.0.0.1orderdeny
,allow
20070312-18:14:31 (24026) rails_env: development
20070312-18:14:31 (24026) timer_sleep: 60
20070312-18:14:31 (24026) port: 22222
20070312-18:14:31 (24026) pool_size: 5
20070312-18:14:31 (24028) Starting worker:
BackgrounDRb::Worker::WorkerLogger backgroundrb_logger (backgroundrb_logger)
()
20070312-18:14:31 (24028) Starting worker:
BackgrounDRb::Worker::WorkerResults backgroundrb_results
(backgroundrb_results) ()
20070312-18:14:31 (24028) Loading Worker Class File:
/home/david/redclay/lib/workers/variant_addition_worker.rb
20070312-18:14:31 (24028) Loading Worker Class File:
/home/david/redclay/lib/workers/variant_remove_worker.rb
20070312-18:14:31 (24028) Loading Worker Class File:
/home/david/redclay/lib/workers/variant_subtraction_worker.rb
20070312-18:14:31 (24028) Loading Worker Class File:
/home/david/redclay/lib/workers/variant_new_worker.rb
20070312-18:14:31 (24028) Loading Worker Class File:
/home/david/redclay/lib/workers/ebay_auction_worker.rb
20070312-18:14:31 (24028) Loading Sechedule:
classebay_auction_workerargsjob_keyebay_auction_runner
classebay_auction_workertrigger_args0 * * * * *
*trigger_typecron_triggerjob_keyebay_auction_runner
#<BackgrounDRb::CronTrigger:0xb73ae12c>
20070312-18:15:00 (24028) Schedule triggered: #<struct #<Class:0xb7956b38>
job=#<Proc:0xb79c1ac8@/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:355>,
trigger=#<BackgrounDRb::CronTrigger:0xb73ae12c @hour=0..23, @year=nil,
@day=1..31, @cron_expr="0 * * * * * *", @sec=[0], @wday=0..6, @min=0..59,
@month=1..12>, earliest=Mon Mar 12 18:15:00 -0700 2007, last=Mon Mar 12
18:15:00 -0700 2007>
20070312-18:15:01 (24028) Starting worker: ebay_auction_worker
ebay_auction_runner (ebay_auction_worker_ebay_auction_runner) ()

....fast-forward 41 minutes.....

20070312-18:56:00 (24028) Starting worker: ebay_auction_worker
ebay_auction_runner (ebay_auction_worker_ebay_auction_runner) ()
20070312-18:57:00 (24028) Schedule triggered: #<struct #<Class:0xb7956b38>
job=#<Proc:0xb79c1ac8@/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:355>,
trigger=#<BackgrounDRb::CronTrigger:0xb73ae12c @hour=0..23, @year=nil,
@day=1..31, @cron_expr="0 * * * * * *", @sec=[0], @wday=0..6, @min=0..59,
@month=1..12>, earliest=Mon Mar 12 18:57:00 -0700 2007, last=Mon Mar 12
18:57:00 -0700 2007>
20070312-18:57:00 (24028) failed to find slave socket - (RuntimeError)
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/slave-1.2.0/lib/slave.rb:435:in
`initialize'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:210:in
`new'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:210:in
`new_worker'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/thread_pool.rb:36:in
`dispatch'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/thread_pool.rb:22:in
`initialize'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/thread_pool.rb:22:in
`new'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/thread_pool.rb:22:in
`dispatch'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:199:in
`new_worker'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:357:in
`schedule_worker'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:46:in
`call'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:46:in
`run'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:40:in
`each'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:40:in
`run'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:35:in
`loop'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:35:in
`run'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:95:in
`run'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:94:in
`initialize'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:94:in
`new'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/scheduler.rb:94:in
`run'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb/middleman.rb:106:in
`setup'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb_server.rb:306:in
`run'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/application.rb:186:in
`call'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/application.rb:186:in
`start_proc'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/daemonize.rb:192:in
`call'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/daemonize.rb:192:in
`call_as_daemon'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/application.rb:190:in
`start_proc'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/application.rb:226:in
`start'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/controller.rb:69:in
`run'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons.rb:182:in
`run_proc'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/cmdline.rb:94:in
`call'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons/cmdline.rb:94:in
`catch_exceptions'
20070312-18:57:00 (24028)
/usr/lib/ruby/gems/1.8/gems/daemons-1.0.4/lib/daemons.rb:181:in
`run_proc'
20070312-18:57:00 (24028)
/home/david/redclay/vendor/plugins/backgroundrb/server/lib/backgroundrb_server.rb:301:in
`run'
20070312-18:57:00 (24028) script/backgroundrb:29
--------------------


It looks like it is dying because a Slave process has somehow killed itself
in that timespan. Can I do something about this? I need this worker to be
running all the time. Is there something I can do in my code to keep
backgroundrb processes from dying? I'd like to figure out how we can resolve
this, because it looks like it might be a much more serious problem in the
backgroundrb framework. That said, I want to express my gratitude for this
framework existing -- I wouldn't have been able to come this far without it.
I hope we can figure this out!

Thanks,
David Balatero
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://rubyforge.org/pipermail/backgroundrb-devel/attachments/20070313/e4b743d9/attachment-0001.html 


More information about the Backgroundrb-devel mailing list