title: Rails + Heroku: Excon Expected([200, 201, 202, 204, 206, 304]) <=> Actual(422 Unprocessable Entity)
body: <p>My Rails application, deployed in Heroku, uses some rake tasks I have defined and scheduled to be executed once a day. Very simple tasks that the only thing they do, is add some jobs to the DelajedJobs table, so a worker gets up and execute them.</p>
  
  <p>Some days ago, all rake jobs started failing. Some example of one of those:</p>
  
  <pre><code># Rakefile
  desc 'Update balances of all organizations'
  task recalculate_balances: :environment do
    Organization.all.each do |organization|
      RecalculateBalancesJob.perform_later(organization)
    end
  end
  </code></pre>
  
  <p>And I saw this exception in my Rollbar account:</p>
  
  <pre><code>Excon::Error::UnprocessableEntity: Expected([200, 201, 202, 204, 206, 304]) &lt;=&gt; Actual(422 Unprocessable Entity)
  + 61 non-project frames
  62
  File "/app/Rakefile", line 22 in block (2 levels) in &lt;top (required)&gt;
  + 2 non-project frames
  65
  File "/app/Rakefile", line 21 in block in &lt;top (required)&gt;
  + 32 non-project frames
  98
  File "/app/bin/bundle", line 3 in load
  99
  File "/app/bin/bundle", line 3 in &lt;main&gt;
  </code></pre>
  
  <p>So what I did was covering with a <code>begin rescue end</code> block, to avoid losing the work there, but I keep seeing same error. There's nothing that gives me a clue about what could be happening. Here's the complete stack trace:</p>
  
  <pre><code>Expected([200, 201, 202, 204, 206, 304]) &lt;=&gt; 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 &lt;module:Logging&gt;'
  /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 &lt;module:Logging&gt;'
  /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 &lt;top (required)&gt;'
  /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 &lt;top (required)&gt;'
  /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 `&lt;main&gt;'
  </code></pre>
  
  <p>I can see this could be related: <a href="https://github.com/heroku/platform-api/issues/74" rel="nofollow noreferrer">https://github.com/heroku/platform-api/issues/74</a></p>
  
  <p>PS: I'm pretty sure there's nothing wrong with the Rails Jobs, because I went manually via <code>rails c</code>, executed one of them, and it all went good.</p>
  
  <pre><code>➜  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&gt; o = Organization.find SOME_ID
  D, [2018-02-28T04:39:43.711584 #5] DEBUG -- :   Organization Load (0.7ms)  SELECT  ...
  irb(main):002:0&gt; 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: #&lt;GlobalID:0x000000070fdaf0 @uri=#&lt;URI::GID gid:some-gid-id&gt;&gt;
  irb(main):003:0&gt;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]) &lt;=&gt; Actual(422 Unprocessable Entity)
  ... and the traceback ...
  </code></pre>
  
  <p>Issue is either with rake, DelayedJob, Workless (gem for heroku workers management), or Excon.</p>
  
  <h1>Additional Info</h1>
  
  <p>I have added the resolution in an answer and converted this question to a Q&amp;A in case is useful for somebody else.</p>