Search code examples
redissidekiqruby-on-rails-6

Rails 6 - sidekiq doesn't dequeue on development


I've had this problem on development : Sidekiq enqueues the job, but never dequeues. On Production (Heroku), everything works fine. Here's a tiny part of the launching messages on my terminal :

2020-06-16T17:39:20.481Z pid=7317 tid=oxx33ap5d INFO: Booted Rails 6.0.2.1 application in development environment
2020-06-16T17:39:20.481Z pid=7317 tid=oxx33ap5d INFO: Running in ruby 2.6.5p114 (2019-10-01 revision 67812) [x86_64-darwin16]
2020-06-16T17:39:20.481Z pid=7317 tid=oxx33ap5d INFO: See LICENSE and the LGPL-3.0 for licensing details.
2020-06-16T17:39:20.482Z pid=7317 tid=oxx33ap5d INFO: Upgrade to Sidekiq Pro for more features and support: http://sidekiq.org
2020-06-16T17:39:20.482Z pid=7317 tid=oxx33ap5d INFO: Booting Sidekiq 6.0.6 with redis options {:id=>"Sidekiq-server-PID-7317", :url=>nil}
2020-06-16T17:39:20.536Z pid=7317 tid=oxx33ap5d DEBUG: Client Middleware: 
2020-06-16T17:39:20.536Z pid=7317 tid=oxx33ap5d DEBUG: Server Middleware: Sidekiq::Failures::Middleware
2020-06-16T17:39:20.536Z pid=7317 tid=oxx33ap5d INFO: Starting processing, hit Ctrl-C to stop
2020-06-16T17:39:20.536Z pid=7317 tid=oxx33ap5d DEBUG: {:queues=>["default", "mailers"], :labels=>[], :concurrency=>3, :require=>".", :environment=>nil, :timeout=>240, :poll_interval_average=>nil, :average_scheduled_poll_interval=>5, :error_handlers=>[#<Sidekiq::ExceptionHandler::Logger:0x00007ffe1b158260>], :death_handlers=>[], :lifecycle_events=>{:startup=>[], :quiet=>[], :shutdown=>[], :heartbeat=>[]}, :dead_max_jobs=>10000, :dead_timeout_in_seconds=>15552000, :reloader=>#<Sidekiq::Rails::Reloader @app=Wadzatsong::Application>, :verbose=>true, :config_file=>"./config/sidekiq.yml", :strict=>true, :tag=>"wadzatsong", :identity=>"MBP-de-apple:7317:18f040a5293c"}
2020-06-16T17:39:20.586Z pid=7317 tid=oxx3b6ag9 class=PlaylistJob jid=9fda5f6075587921f5d3be51 INFO: start
2020-06-16T17:39:20.586Z pid=7317 tid=oxx3b6aid class=PlaylistJob jid=d1b5536379c0a65ec73381f6 INFO: start
2020-06-16T17:39:20.586Z pid=7317 tid=oxx3b6ac1 class=PlaylistJob jid=122c610b9d44942d06652289 INFO: start
2020-06-16T17:39:27.001Z pid=7317 tid=oxx3b6ac1 class=PlaylistJob jid=122c610b9d44942d06652289 elapsed=6.415 INFO: fail
2020-06-16T17:39:27.001Z pid=7317 tid=oxx3b6ac1 WARN: {"context":"Job raised exception","job":{"retry":true,"queue":"default","class":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper","wrapped":"PlaylistJob","args":[{"job_class":"PlaylistJob","job_id":"aa761c60-ead2-44a6-b5ab-41559a595143","provider_job_id":null,"queue_name":"default","priority":null,"arguments":["French"],"executions":0,"exception_executions":{},"locale":"en","timezone":"UTC","enqueued_at":"2020-06-15T17:31:35Z"}],"jid":"122c610b9d44942d06652289","created_at":1592242295.783063,"enqueued_at":1592242295.783238,"error_message":"429 Too Many Requests","error_class":"RestClient::TooManyRequests","processor":"MBP-de-apple:7317","failed_at":1592329166.999786},"jobstr":"{\"retry\":true,\"queue\":\"default\",\"class\":\"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper\",\"wrapped\":\"PlaylistJob\",\"args\":[{\"job_class\":\"PlaylistJob\",\"job_id\":\"aa761c60-ead2-44a6-b5ab-41559a595143\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[\"French\"],\"executions\":0,\"exception_executions\":{},\"locale\":\"en\",\"timezone\":\"UTC\",\"enqueued_at\":\"2020-06-15T17:31:35Z\"}],\"jid\":\"122c610b9d44942d06652289\",\"created_at\":1592242295.783063,\"enqueued_at\":1592242295.783238}"}
2020-06-16T17:39:27.002Z pid=7317 tid=oxx3b6ac1 WARN: RestClient::TooManyRequests: 429 Too Many Requests
2020-06-16T17:39:27.002Z pid=7317 tid=oxx3b6ac1 WARN: /Users/pierre/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/rest-client-2.0.2/lib/restclient/abstract_response.rb:223:in `exception_with_response'
/Users/pierre/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/rest-client-2.0.2/lib/restclient/abstract_response.rb:103:in `return!'
/Users/pierre/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/rest-client-2.0.2/lib/restclient/request.rb:809:in `process_result'
/Users/pierre/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/rest-client-2.0.2/lib/restclient/request.rb:725:in `block in transmit'
/Users/pierre/.rbenv/versions/2.6.5/lib/ruby/2.6.0/net/http.rb:920:in `start'


All the setup seems correct, since it's worked fine on heroku :

config/application.rb
   [...]
    config.active_job.queue_adapter = :sidekiq

sidekiq.yml

:concurrency: 3
:timeout: 240
:verbose: true
:queues:  # Queue priority: https://github.com/mperham/sidekiq/wiki/Advanced-Options
  - default
  - mailers

routes.rb

  Rails.application.routes.draw do
    # Sidekiq Web UI, only for admins.
    require "sidekiq/web"
    authenticate :user, lambda { |u| u.admin } do
      mount Sidekiq::Web => '/sidekiq'
    end
  end

my job :

class PlaylistJob < ApplicationJob
  queue_as :default

  def perform(name)
        [...]
   end
end

and my http://localhost:3000/sidekiq shows the following. I failed the 204 manually, but the 11 retries never succeed

215 Processed
204 Failed
0 Busy
0 Enqueued
11 Retries
0 Scheduled
0 Dead

This setup of Sidekiq for Redis is here initializers/redis.rb :

$redis = Redis.new

url = ENV["REDISCLOUD_URL"]

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

  Sidekiq.configure_client do |config|
    config.redis = { url: url }
  end
  $redis = Redis.new(:url => url)
end

Solution

  • So I found out and fixed it, thanx to cmramseyer's comment, hope I will help with my conclusions here :

    The setup of Sidekiq for Redis is here initializers/redis.rb :

    $redis = Redis.new
    
    url = ENV["REDISCLOUD_URL"]
    
    if url
      Sidekiq.configure_server do |config|
        config.redis = { url: url }
      end
    
      Sidekiq.configure_client do |config|
        config.redis = { url: url }
      end
      $redis = Redis.new(:url => url)
    end
    

    I changed the local url, as indicated by cmramseyer, to

    url = "redis://localhost:6379/0"
    

    Actually, the url channel already in use on production is redis://localhost:6379/1, so I updated this url to match "redis://localhost:6379/1". 0 or 1, important is all the URLs match !

    My development configuration in initializers/cable.yml was set to development: async ! so I updated it to match the same url as previous .

    development:
      adapter: redis
      url: <%= ENV.fetch("REDISCLOUD_URL") { "redis://localhost:6379/1" } %>
      channel_prefix: _wadzatsong_development
    
    test:
      adapter: test
    
    production:
      adapter: redis
      url: <%= ENV.fetch("REDISCLOUD_URL") { "redis://localhost:6379/1" } %>
      channel_prefix: _wadzatsong_production
    

    That's all folks !