0

我在 Heroku 中部署的 Rails 应用程序使用了一些我定义并计划每天执行一次的 rake 任务。非常简单的任务,他们唯一要做的就是将一些作业添加到 DelajedJobs 表中,以便工作人员起床并执行它们。

几天前,所有 rake 作业都开始失败。其中之一的一些例子:

# Rakefile
desc 'Update balances of all organizations'
task recalculate_balances: :environment do
  Organization.all.each do |organization|
    RecalculateBalancesJob.perform_later(organization)
  end
end

我在我的 Rollbar 帐户中看到了这个异常:

Excon::Error::UnprocessableEntity: Expected([200, 201, 202, 204, 206, 304]) <=> Actual(422 Unprocessable Entity)
+ 61 non-project frames
62
File "/app/Rakefile", line 22 in block (2 levels) in <top (required)>
+ 2 non-project frames
65
File "/app/Rakefile", line 21 in block in <top (required)>
+ 32 non-project frames
98
File "/app/bin/bundle", line 3 in load
99
File "/app/bin/bundle", line 3 in <main>

所以我所做的是用一个begin rescue end块覆盖,以避免丢失那里的工作,但我一直看到同样的错误。没有什么可以让我知道可能发生的事情。这是完整的堆栈跟踪:

Expected([200, 201, 202, 204, 206, 304]) <=> Actual(422 Unprocessable Entity)
/app/vendor/bundle/ruby/2.4.0/gems/excon-0.57.1/lib/excon/middlewares/expects.rb:7:in `response_call'
/app/vendor/bundle/ruby/2.4.0/gems/excon-0.57.1/lib/excon/middlewares/response_parser.rb:9:in `response_call'
/app/vendor/bundle/ruby/2.4.0/gems/excon-0.57.1/lib/excon/connection.rb:388:in `response'
/app/vendor/bundle/ruby/2.4.0/gems/excon-0.57.1/lib/excon/connection.rb:252:in `request'
/app/vendor/bundle/ruby/2.4.0/gems/heroics-0.0.23/lib/heroics/link.rb:111:in `request_with_cache'
/app/vendor/bundle/ruby/2.4.0/gems/heroics-0.0.23/lib/heroics/link.rb:66:in `run'
/app/vendor/bundle/ruby/2.4.0/gems/heroics-0.0.23/lib/heroics/resource.rb:28:in `method_missing'
/app/vendor/bundle/ruby/2.4.0/gems/platform-api-2.1.0/lib/platform-api/client.rb:1455:in `update'
/app/vendor/bundle/ruby/2.4.0/gems/workless_revived-2.1.0.2/lib/workless/scalers/heroku.rb:14:in `up'
/app/vendor/bundle/ruby/2.4.0/gems/workless_revived-2.1.0.2/lib/workless/scaler.rb:21:in `block (2 levels) in included'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:396:in `instance_exec'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:396:in `block in make_lambda'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:232:in `block in conditional'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:456:in `block in call'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:456:in `each'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:456:in `call'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:750:in `_run_commit_callbacks'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:354:in `committed!'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:87:in `commit_records'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:178:in `commit_transaction'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:202:in `within_new_transaction'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:211:in `transaction'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:319:in `block in save'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:334:in `rollback_active_record_state!'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/transactions.rb:318:in `save'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/suppressor.rb:41:in `save'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/backend/base.rb:19:in `block (2 levels) in enqueue_job'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/lifecycle.rb:61:in `block in initialize'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/lifecycle.rb:66:in `execute'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/backend/base.rb:17:in `block in enqueue_job'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/backend/base.rb:16:in `tap'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/backend/base.rb:16:in `enqueue_job'
/app/vendor/bundle/ruby/2.4.0/gems/delayed_job-4.1.2/lib/delayed/backend/base.rb:12:in `enqueue'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/queue_adapters/delayed_job_adapter.rb:17:in `enqueue'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/enqueuing.rb:76:in `block in enqueue'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:126:in `call'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:455:in `call'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:448:in `block (2 levels) in around'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:286:in `block (2 levels) in halting'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/logging.rb:15:in `block (3 levels) in <module:Logging>'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/logging.rb:44:in `block in tag_logger'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/tagged_logging.rb:69:in `block in tagged'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/tagged_logging.rb:26:in `tagged'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/tagged_logging.rb:69:in `tagged'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/logging.rb:44:in `tag_logger'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:391:in `instance_exec'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:391:in `block in make_lambda'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:285:in `block in halting'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:447:in `block in around'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:455:in `call'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:750:in `_run_enqueue_callbacks'
/app/vendor/bundle/ruby/2.4.0/gems/activesupport-5.0.1/lib/active_support/callbacks.rb:90:in `run_callbacks'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/enqueuing.rb:72:in `enqueue'
/app/vendor/bundle/ruby/2.4.0/gems/activejob-5.0.1/lib/active_job/enqueuing.rb:18:in `perform_later'
/app/Rakefile:30:in `block (2 levels) in <top (required)>'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/relation/delegation.rb:38:in `each'
/app/vendor/bundle/ruby/2.4.0/gems/activerecord-5.0.1/lib/active_record/relation/delegation.rb:38:in `each'
/app/Rakefile:27:in `block in <top (required)>'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:248:in `block in execute'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:243:in `each'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:243:in `execute'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:187:in `block in invoke_with_call_chain'
/app/vendor/ruby-2.4.0/lib/ruby/2.4.0/monitor.rb:214:in `mon_synchronize'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:180:in `invoke_with_call_chain'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/task.rb:173:in `invoke'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:152:in `invoke_task'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:108:in `block (2 levels) in top_level'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:108:in `each'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:108:in `block in top_level'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:117:in `run_with_threads'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:102:in `top_level'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:80:in `block in run'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:178:in `standard_exception_handling'
/app/vendor/bundle/ruby/2.4.0/gems/rake-11.3.0/lib/rake/application.rb:77:in `run'
/app/bin/rake:9:in `<main>'

我可以看到这可能是相关的:https ://github.com/heroku/platform-api/issues/74

PS:我很确定 Rails Jobs 没有任何问题,因为我手动通过rails c,执行了其中一个,一切顺利。

➜  git:(master) ✗ heroku run bash --remote=production
Running bash on ⬢ my-app-name... up, run.7883 (Hobby)
~ $ rails c
... some libs loading I removed ...
Loading production environment (Rails 5.0.1)
irb(main):001:0> o = Organization.find SOME_ID
D, [2018-02-28T04:39:43.711584 #5] DEBUG -- :   Organization Load (0.7ms)  SELECT  ...
irb(main):002:0> CountStudentsJob.perform_later o
D, [2018-02-28T04:40:02.466393 #5] DEBUG -- : [ActiveJob]    (0.7ms)  BEGIN ...
... here all goes good ...
I, [2018-02-28T04:40:02.916888 #5]  INFO -- : [ActiveJob] Enqueued CountStudentsJob (Job ID: cbba5507-44e5-417d-97e0-11539049784a) to DelayedJob(default) with arguments: #<GlobalID:0x000000070fdaf0 @uri=#<URI::GID gid:some-gid-id>>
irb(main):003:0>exit
~ $ rake recalculate_balances
... some libs loading I removed ...
... lots of organizations loads ...
... until it comes to the same SOME_ID from up ...
Scheduling :recalculate_balances for Organization SOME_ID
D, [2018-02-28T04:40:38.957868 #20] DEBUG -- : [ActiveJob]    (0.5ms)  BEGIN
D, [2018-02-28T04:40:38.960324 #20] DEBUG -- : [ActiveJob]   SQL (0.6ms)  INSERT INTO "delayed_jobs" ("handler", "run_at", "queue", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  [["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper\njob_data:\n  job_class: RecalculateBalancesJob\n  job_id: b41052b9-f964-4325-8736-36014bdf62c6\n  queue_name: default\n  priority: \n  arguments:\n  - _aj_globalid: gid:some-gid\n  locale: es\n"], ["run_at", 2018-02-28 04:40:38 UTC], ["queue", "default"], ["created_at", 2018-02-28 04:40:38 UTC], ["updated_at", 2018-02-28 04:40:38 UTC]]
D, [2018-02-28T04:40:38.962464 #20] DEBUG -- : [ActiveJob]    (1.6ms)  COMMIT
D, [2018-02-28T04:40:38.963943 #20] DEBUG -- : [ActiveJob]    (0.6ms)  SELECT COUNT(*) FROM "delayed_jobs" WHERE "delayed_jobs"."failed_at" IS NULL
D, [2018-02-28T04:40:39.045392 #20] DEBUG -- : [ActiveJob]    (1.0ms)  SELECT COUNT(*) FROM "delayed_jobs" WHERE "delayed_jobs"."failed_at" IS NULL
D, [2018-02-28T04:40:39.046998 #20] DEBUG -- : [ActiveJob]    (0.6ms)  SELECT COUNT(*) FROM "delayed_jobs" WHERE "delayed_jobs"."failed_at" IS NULL
Expected([200, 201, 202, 204, 206, 304]) <=> Actual(422 Unprocessable Entity)
... and the traceback ...

问题出在 rake、DelayedJob、Workless(heroku 工人管理的宝石)或 Excon。

附加信息

我已在答案中添加了解决方案,并将此问题转换为问答,以防对其他人有用。

4

1 回答 1

0

我在这里找到了打印消息的方法:https ://github.com/heroku/platform-api/issues/50

消息是:

Excon error 
{
  "id": "cannot_update_above_limit",
  "limit": 1,
  "message": "Cannot update to more than 1 Hobby size dynos per process type.",
  "size": "Hobby",
  "url": "https://devcenter.heroku.com/articles/dyno-size#default-scaling-limits"
}

所以我联系了 Heroku 支持,因为我有一个 Hobby(第一个付费计划,7 美元/dyno)帐户,他们回复:

你好呀,

这里的问题是,对于“爱好”测功机,您不能同时运行多个进程类型。开始使用调度程序插件的 Dynos 都是一次性 dyno,进程类型为“调度程序”。如果这些计划任务中的任何一个重叠,则它们不能同时运行。

您可以使用 heroku run CLI 命令和调度程序同时启动一次性 dyno,因为 heroku run one-off dyno 的进程类型为 run。

我的调度程序工作不会重叠,因为我的日志,我确信这一点。所以我得出的结论是:

由于使用了 workless-gem,在调度程序完成“调度”作业以供工作人员执行之前,无工作人员开始处理作业的尝试将失败。

(现在,用说唱曲目在后台快速再次阅读)

同时,abegin-rescue-end将自己捕获并打印错误。

更新

感谢@geemus 洞察力,我还将无效的 ENV 变量修改为WORKLESS_MAX_WORKERS: '1',并且错误停止出现。这是因为爱好计划。

于 2018-03-03T23:30:10.110 回答