rack 2.1.2 broken sidekiq

[lizdeika]

For some reason original issues are closed

#1504
#1510
#1522

[giedriusr]

Indeed, why these issues were closed if the bug hasn't been fixed?

[jeremyevans]

Please post the actual error you are receiving, with a full backtrace.

#1504 was reported to work locally with 2-1-stable, so presumably 2.1.2 should work.

#1510 was an issue with mongo_session_store, not Sidekiq, and needs fixes in mongo_session_store.

#1522 was an issue with activerecord-session_store, not Sidekiq, and needs fixes in activerecord-session_store.

[zakihaya]

I updated only rack, and I could not open sidekiq UI with error below.

vendor/bundle/ruby/2.6.0/gems/redis-store-1.5.0/lib/redis/store/namespace.rb:98:in `interpolate'
vendor/bundle/ruby/2.6.0/gems/redis-store-1.5.0/lib/redis/store/namespace.rb:89:in `namespace'
vendor/bundle/ruby/2.6.0/gems/redis-store-1.5.0/lib/redis/store/namespace.rb:7:in `set'
vendor/bundle/ruby/2.6.0/gems/redis-rack-2.0.4/lib/rack/session/redis.rb:61:in `block (2 levels) in set_session'
vendor/bundle/ruby/2.6.0/gems/redis-rack-2.0.4/lib/rack/session/redis.rb:94:in `with'
vendor/bundle/ruby/2.6.0/gems/redis-rack-2.0.4/lib/rack/session/redis.rb:61:in `block in set_session'
vendor/bundle/ruby/2.6.0/gems/redis-rack-2.0.4/lib/rack/session/redis.rb:79:in `with_lock'
vendor/bundle/ruby/2.6.0/gems/redis-rack-2.0.4/lib/rack/session/redis.rb:60:in `set_session'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/session/abstract/id.rb:508:in `write_session'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/session/abstract/id.rb:391:in `commit_session'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/session/abstract/id.rb:271:in `context'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/session/abstract/id.rb:263:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/cookies.rb:670:in `call'
vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/migration.rb:559:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:98:in `run_callbacks'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/executor.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:135:in `call_app'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:30:in `block in call'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:20:in `catch'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:20:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
vendor/bundle/ruby/2.6.0/gems/lograge-0.10.0/lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/rack/logger.rb:28:in `call'
vendor/bundle/ruby/2.6.0/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
vendor/bundle/ruby/2.6.0/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/request_id.rb:27:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/method_override.rb:24:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/runtime.rb:24:in `call'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/executor.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/static.rb:127:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.1.2/lib/rack/sendfile.rb:113:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-cors-1.0.5/lib/rack/cors.rb:98:in `call'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/engine.rb:524:in `call'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.2/lib/puma/configuration.rb:227:in `call'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.2/lib/puma/server.rb:674:in `handle_request'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.2/lib/puma/server.rb:476:in `process_client'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.2/lib/puma/server.rb:334:in `block in run'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.2/lib/puma/thread_pool.rb:135:in `block in spawn_thread'

Updating redis-rack gem, I can open Sidekiq UI.

bundle udpate redis-rack

@lizdeika How about update gems other than rack?

[mikegee]

@zakihaya that looks like a full backtrace, but it doesn't include the error

[jeremyevans]

Considering that the error is in interpolate in redis-store, it's probably the same issue that mongo_session_store and activerecord-session_store has, and apparently it has already been fixed upstream, since updating redis-rack fixes the issue.

[nickjer]

This is what I am seeing when I try to access a sidekiq endpoint (using rack 2.1.1):

NoMethodError: undefined method `transform_keys' for #<ActionDispatch::Request::Session:0x7fa27c3f8e98 not yet loaded>
  from rack/session/abstract/id.rb:212:in `stringify_keys'
  from rack/session/abstract/id.rb:148:in `update'
  from rack/session/abstract/id.rb:317:in `prepare_session'
  from rack/session/abstract/id.rb:276:in `context'
  from rack/session/abstract/id.rb:271:in `call'
  from rack/urlmap.rb:77:in `block in call'
  from rack/urlmap.rb:61:in `each'
  from rack/urlmap.rb:61:in `call'
  from rack/builder.rb:176:in `call'
  from sidekiq/web.rb:104:in `call'
  from sidekiq/web.rb:109:in `call'

Updating to rack 2.1.2 seems to fix it.

[ioquatix]

Repeating @jeremyevans

Please post the actual error you are receiving, with a full backtrace.

If there are actionable errors/issues, we definitely want to know about them! Thanks :)

[lizdeika]

Hi,

we have no rack-redis, redis-rack or anything like that in our application.

2.2.1 is still broken, Sidekiq UI is some cut down html: https://i.imgur.com/lmuT0no.jpg
NoMethodError: undefined method transform_keys'` is gone.
It just fails silently now.

2.0.8 is the latest that just works.

[ioquatix]

@mperham ping

[lizdeika]

We are using Sidekiq Pro 5.0.1 (Sidekiq 6.0.4) if that helps

[ioquatix]

@lizdeika it looks like the content-length is being set wrong. You can try using falcon which ignores the content-length header from rack to confirm (if it works okay with falcon but breaks with puma it's a strong indicator that's the problem).

[lizdeika]

Sadly can not test that as the problem is viable only in production that runs on passenger. We can't just switch web server in production for a test :(
Development environment runs on puma and has no problems with sidekiq.

[ioquatix]

Is your middleware stack different between development and production?

[ioquatix]

Can you try running curl -i against your production system and check what is the content length? Do you have new relic in production too? Because I heard it was causing some issues.

[mperham]

Fixed on Sidekiq master.

[ioquatix]

@mperham what was the issue?

[mikegee]

I'm the wrong Mike, but it looks like New Relic was changing the body after Sidekiq calculated the content-length. sidekiq/sidekiq@675e40c

[ioquatix]

@mikegee thanks for the link, looks like the issue is fixed. I filed a bug report in NR newrelic/newrelic-ruby-agent#318, because changing the body and not deleting/updating the content-length seems like the root cause.

[lizdeika]

Now that was deep :) Thanks everyone!
@mperham any chance for the fixes in Sidekiq 6.0.5 with unlocked rack version?