Sidekiq fails to start

[codespectator]

So with a vanilla ubuntu box with redis installed default (at the moment) via aptitude. When attempting to start sidekiq I get the following output:

2013-05-09T18:01:52Z 4636 TID-oto60q0pg INFO: Booting Sidekiq 2.5.3 with Redis at redis://localhost:6379/0
2013-05-09T18:01:52Z 4636 TID-oto60q0pg INFO: Running in ruby 2.0.0p0 (2013-02-24 revision 39474) [x86_64-linux]
2013-05-09T18:01:52Z 4636 TID-oto60q0pg INFO: See LICENSE and the LGPL-3.0 for licensing details.
2013-05-09T18:01:53Z 4636 TID-oto60q0pg INFO: Starting processing, hit Ctrl-C to stop
2013-05-09T18:01:57Z 4636 TID-oto1w6jvo WARN: {:context=>"scheduling poller thread died!"}
2013-05-09T18:01:57Z 4636 TID-oto1w6jvo WARN: undefined method each' for nil:NilClass 2013-05-09T18:01:57Z 4636 TID-oto1w6jvo WARN: /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/scheduled.rb:36:inblock (3 levels) in poll'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/scheduled.rb:30:in each' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/scheduled.rb:30:inblock (2 levels) in poll'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/connection_pool-0.9.3/lib/connection_pool.rb:49:in with' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq.rb:67:inredis'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/scheduled.rb:29:in block in poll' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/util.rb:15:inwatchdog'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.5.3/lib/sidekiq/scheduled.rb:22:in poll' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/celluloid-0.12.4/lib/celluloid/calls.rb:53:inpublic_send'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/celluloid-0.12.4/lib/celluloid/calls.rb:53:in dispatch' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/celluloid-0.12.4/lib/celluloid/actor.rb:327:inblock in handle_message'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/celluloid-0.12.4/lib/celluloid/tasks/task_fiber.rb:24:in `block in initialize'

netstat -tap shows redis running on default ports:

tcp 0 0 localhost:6379 : LISTEN -

Any ideas? If you need anything else let me know.

[mperham]

Your sidekiq is about 6 months old. Try the latest.

[codespectator]

I have updated the version of sidekiq to the latest and now I am getting this:

2013-05-10T09:35:06Z 4226 TID-owgrngnj0 INFO: Booting Sidekiq 2.11.2 using redis://localhost:6379/0 with options {}
2013-05-10T09:35:06Z 4226 TID-owgrngnj0 INFO: Running in ruby 2.0.0p0 (2013-02-24 revision 39474) [x86_64-linux]
2013-05-10T09:35:06Z 4226 TID-owgrngnj0 INFO: See LICENSE and the LGPL-3.0 for licensing details.
private method `select' called for nil:NilClass
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/api.rb:73:in `block in cleanup'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/connection_pool-1.0.0/lib/connection_pool.rb:48:in `with'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq.rb:67:in `redis'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/api.rb:70:in `cleanup'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/cli.rb:55:in `run'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/bin/sidekiq:8:in `<top (required)>'
/var/app/qohort/shared/bundle/ruby/2.0.0/bin/sidekiq:23:in `load'
/var/app/qohort/shared/bundle/ruby/2.0.0/bin/sidekiq:23:in `<main>'

As a little test to see what redis was doing I did this:

redis = Redis.new
redis.set('test','test')
=> nil
redis.get('test')
=> nil
redis.client.connection.connected?
=> true
redis.client.connected?
=> true

Redis is not logging any errors to the log files and now I am really stuck. My sidekiq initializer looks like this:

Sidekiq.configure_server do |config|
  config.server_middleware do |chain|
    chain.add Kiqstand::Middleware
  end
end

Sidekiq.configure_client do |config|
  config.redis = { size: 16 }
end

[mperham]

I suspect you have a Redis client monkeypatch which breaks the Redis KEYS return value. KEYS should always return an array, even if empty, never nil.

irb(main):001:0> require 'redis-namespace'
=> true
irb(main):002:0> r = Redis::Namespace.new('foo')
=> #<Redis::Namespace:0x007fc5e43f0f00 @namespace="foo", @redis=#<Redis client v3.0.4 for redis://127.0.0.1:6379/0>>
irb(main):003:0> r.keys('bar:*')
=> []

[mperham]

BTW, it's pretty unusual to have a client size of 16. Are you using puma or some other multi-threaded web server?

[codespectator]

The client size 16 is because I am using puma and your docs suggest that you set it the the max thread count which on puma is 16

[mperham]

Perfect. 👍

[codespectator]

I have been doing more debugging and here is what I have so far:

On my local machine (OSX) I have this project which is running ruby 2.0 and the latest version of sidekiq and 3.0.2 on redis. Just simple tests show the following when trying to interact with redis:

r = Redis.new
r.set 'test','test'
#=> nil
r.get 'test'
#=> nil

With a different app also using redis-rb 3.0.2 the same in console behaves correctly.
I am doing nothing with redis apart from using it for sidekiq, so not sure what is going on. Although not sure it is Sidekiq related.

[codespectator]

[5] pry(main)> redis = Redis::Namespace.new('foo')
=> #<Redis::Namespace:0x007ff940be93d0
@namespace="foo",
@redis=#<Redis client v3.0.2 for redis://127.0.0.1:6379/0>>
[6] pry(main)> redis.keys('bar:*')
=> nil

[mperham]

Upgrade the Redis and Redis-namespace gems.

On 10 May 2013, at 10:09, James MacLeod notifications@github.com wrote:

[5] pry(main)> redis = Redis::Namespace.new('foo')
=> # @namespace="foo",
@redis=#>
[6] pry(main)> redis.keys('bar:*')
=> nil

—
Reply to this email directly or view it on GitHub.

[codespectator]

ok from the gemfile.lock:

redis (3.0.4)
redis-namespace (1.3.0)
redis (~> 3.0.0)

and still this:

2013-05-10T14:50:15Z 4515 TID-ows0pwc2k INFO: Booting Sidekiq 2.11.2 using redis://localhost:6379/0 with options {}
2013-05-10T14:50:15Z 4515 TID-ows0pwc2k INFO: Running in ruby 2.0.0p0 (2013-02-24 revision 39474) [x86_64-linux]
2013-05-10T14:50:15Z 4515 TID-ows0pwc2k INFO: See LICENSE and the LGPL-3.0 for licensing details.
private method select' called for nil:NilClass /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/api.rb:73:inblock in cleanup'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/connection_pool-1.0.0/lib/connection_pool.rb:48:in with' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq.rb:67:inredis'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/api.rb:70:in cleanup' /var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/lib/sidekiq/cli.rb:55:inrun'
/var/app/qohort/shared/bundle/ruby/2.0.0/gems/sidekiq-2.11.2/bin/sidekiq:8:in <top (required)>' /var/app/qohort/shared/bundle/ruby/2.0.0/bin/sidekiq:23:inload'
/var/app/qohort/shared/bundle/ruby/2.0.0/bin/sidekiq:23:in `

'

[mperham]

According to the redis gem's API docs, keys should never return nil. There's either a bug in the gem or there's a monkeypatch which is breaking that API. Either way, Sidekiq is using the API as documented.

[codespectator]

Thanks, the only thing that I could think of that was doing anything with redis (apart from sidekiq) was appsignal-redis-1.0.0.rc1.gem, removed that and sure enough, happy days!

[thijsc]

There was a bug in this version of the appsignal-redis gem that modified the query hash when it should only clean up the copy of the query hash that's used in a notification. This broken behavior does not occur in the current version of the gem. Sorry about the impact this gem version had @codespectator.