Sidekiq: ERROR: Job 'at' must be a Numeric timestamp

Created on 21 Oct 2019 · 21Comments · Source: mperham/sidekiq

Ruby version: 2.6.5
Sidekiq / Pro / Enterprise version(s): Base version (free)
Rails version: 6.0.0
Sidekiq: 6.0.2

This is on Heroku.

Initializer -

Sidekiq.logger.level = Rails.env.development? ? Logger::INFO : Logger::WARN

Sidekiq::Extensions.enable_delay!

Sidekiq.configure_client do |config|
  config.redis = { url: Settings.redis.url }
end

Sidekiq.configure_server do |config|
  config.redis = { url: Settings.redis.url }
end

# Web Dashboard
require 'sidekiq/web'
if Rails.env.staging? || Rails.env.production?
  Sidekiq::Web.use Rack::Auth::Basic do |username, password|
    username == Settings.sidekiq.admin.username && password == Settings.sidekiq.admin.password
  end
end

Error (its weird that I don't see any further stack-trace, this is all I see in my logs)

2019-10-21T21:28:27.619526+00:00 app[worker_a.4]: pid=4 tid=gtl7j5bd8 ERROR: Job 'at' must be a Numeric timestamp
2019-10-21T21:28:27.619566+00:00 app[worker_a.4]: pid=4 tid=gtl7j5bd8 WARN: ArgumentError: Job 'at' must be a Numeric timestamp
2019-10-21T21:28:27.619697+00:00 app[worker_a.4]: pid=4 tid=gtl7j5bd8 WARN: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/client.rb:225:in `normalize_item'
2019-10-21T21:28:27.619701+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/client.rb:70:in `push'
2019-10-21T21:28:27.619703+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/client.rb:136:in `push'
2019-10-21T21:28:27.619706+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:27:in `block (3 levels) in enqueue_jobs'
2019-10-21T21:28:27.619708+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:22:in `each'
2019-10-21T21:28:27.619710+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:22:in `block (2 levels) in enqueue_jobs'
2019-10-21T21:28:27.619712+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:16:in `each'
2019-10-21T21:28:27.619714+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:16:in `block in enqueue_jobs'
2019-10-21T21:28:27.619716+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq.rb:97:in `block in redis'
2019-10-21T21:28:27.619719+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:65:in `block (2 levels) in with'
2019-10-21T21:28:27.619721+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:64:in `handle_interrupt'
2019-10-21T21:28:27.619723+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:64:in `block in with'
2019-10-21T21:28:27.619726+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:61:in `handle_interrupt'
2019-10-21T21:28:27.619728+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.2/lib/connection_pool.rb:61:in `with'
2019-10-21T21:28:27.619730+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq.rb:94:in `redis'
2019-10-21T21:28:27.619732+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:15:in `enqueue_jobs'
2019-10-21T21:28:27.619734+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:78:in `enqueue'
2019-10-21T21:28:27.619737+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/scheduled.rb:70:in `block in start'
2019-10-21T21:28:27.619739+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/util.rb:15:in `watchdog'
2019-10-21T21:28:27.619741+00:00 app[worker_a.4]: /app/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.2/lib/sidekiq/util.rb:24:in `block in safe_thread'
2019-10-21T21:28:27.627752+00:00 app[worker_a.4]: I, [2019-10-21T21:28:27.627626 #4]  INFO -- : Sending event c64c133cf05142beb2c780aa660040a4 to Sentry

Source

kapso

All 21 comments

Please look at the changelog before opening issues:

https://github.com/mperham/sidekiq/blob/master/Changes.md#head

mperham on 21 Oct 2019

👍1

Ah yes, sorry looked past the HEAD section and went straight to 6.0.2 changes. Thanks for the quick response : )

kapso on 21 Oct 2019

👍1

I just updated to gem 'sidekiq', github: 'mperham/sidekiq', branch: 'master' ...but still seeing the same issue.

kapso on 22 Oct 2019

You'd need to clear out the bad jobs in the retry queue. The code doesn't handle the bad jobs in Redis, just doesn't create new ones.

mperham on 22 Oct 2019

Hold on...

mperham on 22 Oct 2019

Ok, master should now gracefully correct the bad data. bundle up sidekiq and see if the error goes away.

mperham on 22 Oct 2019

Updated the gem, but seeing same issue.

kapso on 22 Oct 2019

Oh right, that code needs to go before the payload validation.

On Oct 21, 2019, at 15:47, Kapil notifications@github.com wrote:

Updated the gem, but seeing same issue.

—
You are receiving this because you modified the open/close state.
Reply to this email directly, view it on GitHub, or unsubscribe.

mperham on 22 Oct 2019

Ok, try again.

On Mon, Oct 21, 2019 at 3:47 PM Kapil notifications@github.com wrote:

Updated the gem, but seeing same issue.

—
You are receiving this because you modified the open/close state.
Reply to this email directly, view it on GitHub
https://github.com/mperham/sidekiq/issues/4345?email_source=notifications&email_token=AAAAWX77DFK3QKTJUJ2GHLLQPYWQFA5CNFSM4JDFOC6KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEB4BFZY#issuecomment-544740071,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAAAWX3TUIZMMSZAAN3WNY3QPYWQFANCNFSM4JDFOC6A
.

mperham on 22 Oct 2019

Yes looks like its fixed, thanks.

kapso on 22 Oct 2019

@mperham Sidekiq Pro customers here, this is biting us after upgrading to Sidekiq Pro 5, which requires Sidekiq 6.0.2.

Do you have an estimated time to release a fixed version of the sidekiq gem?

ms-ati on 25 Oct 2019

A workaround is to use master in your Gemfile. I will release 6.0.3 on Monday.

On Oct 25, 2019, at 09:46, Marc Siegel notifications@github.com wrote:

@mperham Sidekiq Pro customers here, this is biting us after upgrading to Sidekiq Pro 5, which requires Sidekiq 6.0.2.

Do you have an estimated time to release a fixed version of the sidekiq gem?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or unsubscribe.

mperham on 25 Oct 2019

@mperham Ok, we can do that. Just checking -- are you aware that an implication of this bug is that retries are being dropped? That's what we're observing in production. Seems like a pretty serious issue to leave to Monday without an announcement to all Sidekiq Pro customers, do you agree?

ms-ati on 25 Oct 2019

Most Sidekiq Pro customers have not upgraded to 6.0 but it is a serious issue involving potential job loss. I pushed 6.0.3 just now.

mperham on 25 Oct 2019

🎉1

Ah interesting. Perhaps we should not have upgraded? Thanks so much @mperham for the expedited fix and gem release, I will kill my PR to pin to the fix with a new one to take 6.0.3.

Have a great weekend!

ms-ati on 25 Oct 2019

The more critical a piece of infrastructure, the more important it is that you hang back and give a major release time to "settle" and shake out any bugs.

mperham on 25 Oct 2019

Certainly @mperham. Did you know that upgrading from Sidekiq Pro 4 to 5, in the absence of pinning the Sidekiq version, pulled in 6.0.2? In the future we will know to watch out for this effect.

ms-ati on 25 Oct 2019

For maximum clarity: Do you recommend pinning Sidekiq to the matching major version of Sidekiq Pro?

ms-ati on 25 Oct 2019

Can you clarify @mperham did we perhaps misread https://github.com/mperham/sidekiq/blob/master/Pro-5.0-Upgrade.md

Sidekiq Pro 5.0 is mainly a cleanup release for Sidekiq 6.0. The migration should be as close to trivial as a major version bump can be. Note that Sidekiq 6.0 does have major breaking changes
...

Requires Sidekiq 6.0+.

ms-ati on 25 Oct 2019

I bump major versions together. Sidekiq 5 and Sidekiq Pro 4 are matched pairs. Sidekiq 6 and Sidekiq Pro 5 are paired. They are designed to be used together.

If you upgrade to Sidekiq Pro 5, it itself is not a big upgrade but the underlying Sidekiq 6 upgrade is much more significant. Thus the note and and in fact, this bug is an example of that.

So yes, pin your Sidekiq major version and be careful bumping it.

mperham on 25 Oct 2019

Here's an interesting observation, after upgrading to 6.0.3 (from master/head) I am seeing the workers (on Heroku) consuming more memory (last 24 hours timeline). Sidekiq upgrade was the only change.

Screen Shot 2019-10-25 at 5 00 28 PM