rufus 调度程序每次运行两次答案

【问题标题】：rufus scheduler running twice each timerufus 调度程序每次运行两次
【发布时间】：2014-05-26 17:08:58
【问题描述】：

也许这是我的任务，也许是我的调度程序，但由于某种原因，我的调度任务运行了两次或将两个版本保存到数据库。这是我的代码：

report.rb:

  def record_page_stats!
    oauth = Koala::Facebook::OAuth.new
    @api = Koala::Facebook::API.new oauth.get_app_access_token
    @fb_page = @api.get_object(self.fb_page_id)
    self.page_stats.new(like_count: @fb_page["likes"], talking_about_count: @fb_page["talking_about_count"])
    self.save
  end

和 scheduler.rb:

require 'rufus-scheduler'

scheduler = Rufus::Scheduler.new

scheduler.every '10m' do
  Report.where(tracking_page: true).each do |report|
    report.record_page_stats!
  end
end

我是否遗漏了一些非常明显的东西？这是已保存页面统计信息的数据库的输出：

2013-12-20 18:43:06 UTC = 8304 likes and 229 talking about count 
2013-12-20 18:43:08 UTC = 8304 likes and 229 talking about count 
2013-12-20 18:53:06 UTC = 8304 likes and 229 talking about count 
2013-12-20 18:53:08 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:03:06 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:03:08 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:13:06 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:13:08 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:23:07 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:23:33 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:33:06 UTC = 8304 likes and 229 talking about count 
2013-12-20 19:33:32 UTC = 8304 likes and 229 talking about count

从时间戳可以看出，它每 10 分钟运行两次

编辑：

刚刚又看了一遍数据……调度器改了几次时间：

首先，它连续运行两次作业，每次 10 分钟
然后，它切换到每 10 分钟一次
然后，它切换到每 5 分钟一次
然后，它切换到每 5 分钟两次

编辑 2：锁定后的新输出：

2013-12-20 22:14:22 UTC = 176155 likes and 5757 talking about count 
2013-12-20 22:14:24 UTC = 176155 likes and 6994 talking about count

我的文件现在看起来像这样：

require 'rufus-scheduler'

scheduler = Rufus::Scheduler.new(:lockfile => ".rufus-scheduler.lock")

scheduler.every '10m' do
  Report.where(tracking_page: true).each do |report|
    report.record_page_stats!
  end
  log "started Scheduler #{scheduler.object_id}"
end

但是在 heroku 日志中有一个错误：

2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440   job:
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440     Rufus::Scheduler::EveryJob "10m" {}
2013-12-20T22:44:42.625951+00:00 app[worker.1]: { 70149016354440 rufus-scheduler intercepted an error:
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440   error:
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440     70149016354440
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440     ArgumentError
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440     wrong number of arguments (1 for 0)
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/yard-0.8.7.3/lib/yard/globals.rb:16:in `log'
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:224:in `call'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:224:in `do_trigger'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:269:in `block (3 levels) in start_work_thread'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:272:in `call'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:272:in `block (2 levels) in start_work_thread'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:258:in `loop'
2013-12-20T22:44:42.626163+00:00 app[worker.1]:   70149016354440       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:258:in `block in start_work_thread'
2013-12-20T22:44:42.626163+00:00 app[worker.1]: } 70149016354440 .
2013-12-20T22:44:42.625951+00:00 app[worker.1]:   70149016354440       /app/config/initializers/scheduler.rb:9:in `block in <top (required)>'
2013-12-20T22:44:44.472460+00:00 app[web.1]: { 69970029016200 rufus-scheduler intercepted an error:
2013-12-20T22:44:44.472460+00:00 app[web.1]:   69970029016200   job:
2013-12-20T22:44:44.472460+00:00 app[web.1]:   69970029016200     Rufus::Scheduler::EveryJob "10m" {}
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200     ArgumentError
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200     wrong number of arguments (1 for 0)
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/yard-0.8.7.3/lib/yard/globals.rb:16:in `log'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:224:in `call'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:224:in `do_trigger'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:269:in `block (3 levels) in start_work_thread'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:272:in `call'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:272:in `block (2 levels) in start_work_thread'
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:258:in `loop'
2013-12-20T22:44:44.473000+00:00 app[web.1]:   69970029016200       /app/vendor/bundle/ruby/2.0.0/gems/rufus-scheduler-3.0.3/lib/rufus/scheduler/jobs.rb:258:in `block in start_work_thread'
2013-12-20T22:44:44.472460+00:00 app[web.1]:   69970029016200   error:
2013-12-20T22:44:44.472460+00:00 app[web.1]:   69970029016200     69970029016200
2013-12-20T22:44:44.472615+00:00 app[web.1]:   69970029016200       /app/config/initializers/scheduler.rb:9:in `block in <top (required)>'
2013-12-20T22:44:44.473000+00:00 app[web.1]: } 69970029016200 .

【问题讨论】：

如果您阅读我的回答，我会说“类似'log "xyz"'”。我不是说“完全输入这个”。如果您花时间阅读错误而不是直接将其粘贴到此处（就像您不假思索地将我的建议直接粘贴到您的代码中），您可能已经学到了一些东西。你想让我用谷歌搜索从 Heroku 上运行的 Rails 应用程序登录的正确方法，然后向你解释吗？我假设您知道如何记录，因为您的初始问题报告提供了一些日志输出... -1
而且您将“已启动的调度程序”消息放入计划作业中，而不是在调度程序初始化之后，您是否意识到您必须等待 10 分钟才能确定有多少调度程序正在运行?你等了 10 分钟才看到这些错误，甚至没有意识到复制粘贴并不总是一个好主意？呜呜呜……
一件好事：您粘贴的日志显示两个进程正在运行“worker.1”和“web.1”。你的两个调度器。 rufus-scheduler 没什么问题。

标签： ruby-on-rails heroku rufus-scheduler

【解决方案1】：

因此，根据您在问题上放置的标签，您使用的是 Ruby on Rails。

我的印象是您有两个调度程序正在运行（一个在第一个调度程序之后 2 秒初始化，如日志输出所示）。

你可以很容易地放置类似的东西

log "started Scheduler #{scheduler.object_id}"

在调度器初始化之后看看发生了什么。

你没有提到你在什么之上运行 Rails（Webrick、Passenger、Thin、Unicorn，...？）。其中一些运行 Rails 进程的多个副本。

您可以使用 rufus-scheduler 中的锁定系统来阻止第二个（或第三个...）调度程序启动。

对于一个简单的锁定机甲：https://github.com/jmettraux/rufus-scheduler/#lockfile--mylockfiletxt

如果您需要更多（可能在不同主机上运行多个 Rails）：https://github.com/jmettraux/rufus-scheduler/#advanced-lock-schemes

您在 EDIT 中看到的变化可能与服务器派生新的 Rails 副本以应对需求有关。

【讨论】：

我尝试了锁定，但它似乎不起作用。它仍然记录两条记录，现在记录具有不同的值！见新编辑。第二个值应该是相同的，因为它们是相隔几秒记录的。
我们仍然不知道您在运行它的基础上。
我不确定你在上面运行它是什么意思......我在 heroku 上运行它......对不起，如果这是一个简单的问题。另外，我如何知道有多少调度程序正在运行？最后，我只是查看了 heroku 目录，并且假定从 lock 命令创建的文件不存在。
你应该提到你在 Heroku 上运行。我们怎么可能猜到？我在回答中写了一些关于记录调度程序对象 id 的内容，现在就做，如果你看到多个调度程序 id 出现，那么你有多个调度程序正在运行。我花时间写了一个答案，请阅读。
很抱歉。我添加了它，正在等待结果。

【解决方案2】：

所以你在 Heroku 上。

这可能会有所帮助：https://devcenter.heroku.com/articles/clock-processes-ruby

如果您多用 google 或搜索 heroku 文档，您会发现其他地方解释了如何运行除 Rails 进程之外的特殊进程，例如调度程序和后台工作人员。

这也可能有帮助：https://devcenter.heroku.com/articles/procfile

【讨论】：