Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Session cookie deserializing throws error after upgrade to 4.1 #21370

Closed
agis opened this issue Aug 25, 2015 · 4 comments
Closed

Session cookie deserializing throws error after upgrade to 4.1 #21370

agis opened this issue Aug 25, 2015 · 4 comments

Comments

@agis
Copy link
Contributor

agis commented Aug 25, 2015

I'm in the process of upgrading a mature Rails app from 3.2 to 4.2 and stumbled upon an issue when upgraded from 4.0 to 4.1.

I've set the Marshal serializer and haven't set config.secret_key_base at all, in order to preserve the very-same behavior we had with 3.2:

config.action_dispatch.cookies_serializer = :marshal

Now, as soon as I switch to the Rails 4.2 branch and try to write something in the session, I get:

session["foo"] = "bar"

NoMethodError: undefined method `stringify_keys!' for #<String:0x007fc92a4c6c60>
from /Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb:93:in `block in unpacked_cookie_data'

I've inspected the value of data at that point the exception is raised, and in fact they're encoded with Marshal:

From: /Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb @ line 91 ActionDispatch::Session::CookieStore#unpacked_cookie_data:

    87: def unpacked_cookie_data(env)
    88:   env["action_dispatch.request.unsigned_session_cookie"] ||= begin
    89:     stale_session_check! do
    90:       if data = get_cookie(env)
 => 91:         require 'pry'; binding.pry
    92:         data.stringify_keys!
    93:       end
    94:       data || {}
    95:     end
    96:   end
    97: end

[1] pry(#<ActionDispatch::Session::CookieStore>)> data
=> "\x04\b{\tI\"\x0Fsession_id\x06:\x06ETI\"%a82ab787f49c1f40032cf01b5ee68295\x06;\x00TI\"\vlocale\x06;\x00TI\"\nel_GR\x06;\x00TI\"\x10_csrf_token\x06;\x00FI\"1gTnZivTTQ6N0ZeH95eUQ2fLhAyCE9ynTqHBI3SUhTug=\x06;\x00FI\"\x10compare_ids\x06;\x00F{\x00"

It seems that a data = Marshal.load(data) fixes the issue, but I'm don't know if this should happen at all and what's the proper way to fix this. Or maybe this is an issue in my configuration.

@pixeltrix
Copy link
Contributor

@agis- can you drop into pry in this method: https://github.com/rails/rails/blob/v4.1.2/actionpack/lib/action_dispatch/middleware/cookies.rb#L421-L431 and tell use the value of serializer, name and value - thanks.

@agis
Copy link
Contributor Author

agis commented Aug 25, 2015

@pixeltrix I did, that method is not called.

Note that this happens even when I'm just trying to access the session in a middleware like so:

module Rack
  class MyMiddleware
    def initialize(app)
      @app = app
    end

    def call(env)
      request = ActionDispatch::Request.new(env)
      request.env['rack.session']['foo'] # BOOM!

      @app.call(env)
    end
  end
end

Here's a complete backtrace of the exception:

/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb:93:in `block in unpacked_cookie_data'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/abstract_store.rb:51:in `stale_session_check!'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb:89:in `unpacked_cookie_data'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb:73:in `block in load_session'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/abstract_store.rb:51:in `stale_session_check!'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/session/cookie_store.rb:72:in `load_session'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/request/session.rb:180:in `load!'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/request/session.rb:176:in `load_for_write!'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/request/session.rb:109:in `[]='
/Users/agis/dev/foo/lib/rack/my_middleware.rb:21:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/api-versions-1.2.0/lib/api-versions/middleware.rb:22:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/etag.rb:23:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/conditionalget.rb:25:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/head.rb:11:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/params_parser.rb:27:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/flash.rb:254:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/session/abstract/id.rb:225:in `context'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/session/abstract/id.rb:220:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/cookies.rb:563:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/activerecord-4.1.12/lib/active_record/query_cache.rb:36:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/activerecord-4.1.12/lib/active_record/connection_adapters/abstract/connection_pool.rb:621:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
/Users/agis/.gem/ruby/2.1.5/gems/activesupport-4.1.12/lib/active_support/callbacks.rb:82:in `run_callbacks'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/reloader.rb:73:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/remote_ip.rb:76:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/rack/logger.rb:38:in `call_app'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/rack/logger.rb:20:in `block in call'
/Users/agis/.gem/ruby/2.1.5/gems/activesupport-4.1.12/lib/active_support/tagged_logging.rb:68:in `block in tagged'
/Users/agis/.gem/ruby/2.1.5/gems/activesupport-4.1.12/lib/active_support/tagged_logging.rb:26:in `tagged'
/Users/agis/.gem/ruby/2.1.5/gems/activesupport-4.1.12/lib/active_support/tagged_logging.rb:68:in `tagged'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/rack/logger.rb:20:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/quiet_assets-1.0.2/lib/quiet_assets.rb:18:in `call_with_quiet_assets'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/request_id.rb:21:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/methodoverride.rb:21:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/runtime.rb:17:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/activesupport-4.1.12/lib/active_support/cache/strategy/local_cache_middleware.rb:26:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/lock.rb:17:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/actionpack-4.1.12/lib/action_dispatch/middleware/static.rb:84:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/sendfile.rb:112:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/engine.rb:514:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/application.rb:144:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/railtie.rb:194:in `public_send'
/Users/agis/.gem/ruby/2.1.5/gems/railties-4.1.12/lib/rails/railtie.rb:194:in `method_missing'
/Users/agis/.gem/ruby/2.1.5/gems/newrelic_rpm-3.12.0.288/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/lock.rb:17:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/content_length.rb:14:in `call'
/Users/agis/.gem/ruby/2.1.5/gems/rack-1.5.5/lib/rack/handler/webrick.rb:60:in `service'
/Users/agis/.rubies/ruby-2.1.5/lib/ruby/2.1.0/webrick/httpserver.rb:94:in `run'
/Users/agis/.rubies/ruby-2.1.5/lib/ruby/2.1.0/webrick/server.rb:295:in `block in start_thread'

@agis
Copy link
Contributor Author

agis commented Aug 25, 2015

@pixeltrix Just realized this was a nasty monkeypatch in the app which I knew nothing about. Duh! 😫

Sorry for the fuss and thanks for your time! :)

@agis agis closed this as completed Aug 25, 2015
@pixeltrix
Copy link
Contributor

@agis- thanks for coming back and closing - saves us wondering what happened 😄

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants