get session from env instead of request

[zvkemp]

Rack::Session and ActionDispatch::Session populate env['rack.session'] with an empty hash unless another value has already been set (e.g., a session object). If any errors are rescued or reported in middleware between Rollbar's middleware and the default Rails session initialization middleware, this value would have been set, and will create issues when trying to prepare the session later on. I.e., calling Rollbar too early nukes the request by mutating the env.

Issue found on Rack 1.5.5, Rails 4.1.16. Newer versions of Rack also set this default value (but in a slightly different way), so it should apply there as well.

[rokob]

Okay so the way I read the Rack::Request code is that this line is roughly equivalent to

session = env.fetch('rack.session', nil)
if session.nil?
    env['rack.session'] = {}
    session = env['rack.session']
end

In other words, Rack::Request modifies the underlying env by setting the rack.session header if it is missing. So using the Rack::Request to pull the session introduces an ordering issue into the middleware.

[rokob]

We just want the session, but we don't want to modify the underlying env, so in theory this will fetch the same value that rack_req.session does if it is already set, otherwise it returns an empty hash if it is not set (which is the same as rack_req.session). The only difference is that env['rack.session'] does not get set to {} if it was undefined.

[rokob]

I think this is a good change, it removes the side effect of modifying the environment due to our session access. This leads me to the additional question of whether we should be using the env to access the cookies directly via rack.request.cookie_hash rather than using Rack::Request to again modify the env directly.

[rokob]

Is there a simple example reproduction of what bug this is causing? I am see that there is an ordering issue with the middlewares, but can you describe the specific series of events that leads to hitting this? It would be useful for making a test so that it is clear why we are using the env directly. @jondeandres do you have any insight into why we are using Rack::Request and therefore modifying the underlying env?

[jondeandres]

I think we would need to know the exact problems that this is causing because it doesn't look to be an error in our side. We are using the request object where we can because it encapsulates the logic to access its data.

In the case of fetching rack.session the logic is obvious, but it's not so obvious on other cases.

[zvkemp]

Here's a callstack emanating from a call to Rollbar.warning in a piece of middleware situated between Rollbar's and ActionDispatch's session initializer:

.../rollbar-gem/lib/rollbar/request_data_extractor.rb:205:in `rollbar_request_session'
.../rollbar-gem/lib/rollbar/request_data_extractor.rb:34:in `extract_request_data_from_rack'
.../rollbar-gem/lib/rollbar/middleware/rails/rollbar.rb:58:in `extract_request_data'
.../rollbar-gem/lib/rollbar/middleware/rails/rollbar.rb:50:in `request_data'
.../rollbar-gem/lib/rollbar/middleware/rails/rollbar.rb:43:in `block in fetch_scope'
.../rollbar-gem/lib/rollbar/lazy_store.rb:70:in `find_value'
.../rollbar-gem/lib/rollbar/lazy_store.rb:62:in `load_value'
.../rollbar-gem/lib/rollbar/lazy_store.rb:37:in `[]'
.../rollbar-gem/lib/rollbar/util.rb:77:in `block in deep_merge'
.../rollbar-gem/lib/rollbar/lazy_store.rb:74:in `each_key'
.../rollbar-gem/lib/rollbar/lazy_store.rb:74:in `method_missing'
.../rollbar-gem/lib/rollbar/util.rb:72:in `deep_merge'
.../rollbar-gem/lib/rollbar/item.rb:92:in `build_data'
.../rollbar-gem/lib/rollbar/item.rb:62:in `build'
.../rollbar-gem/lib/rollbar/notifier.rb:426:in `build_item'
.../rollbar-gem/lib/rollbar/notifier.rb:370:in `report'
.../rollbar-gem/lib/rollbar/notifier.rb:143:in `log'
.../rollbar-gem/lib/rollbar/notifier.rb:168:in `warning'
.../.rbenv/versions/2.3.3/lib/ruby/2.3.0/forwardable.rb:189:in `warning'

@jondeandres This isn't the only situation I've seen where using the request objects in middleware can cause unrecoverable errors (because they mutate the env). I would love for that not to be the case.

I created a rails app as a minimal reproducible example: https://github.com/zvkemp/rollbar-session-repro. This is a plain rails app (-ActiveRecord, +Rollbar). Only code modifications are in https://github.com/zvkemp/rollbar-session-repro/blob/master/config/initializers/session_store.rb.

[zvkemp]

Oh, and the error you should expect to see when you request / (aside from a warning about an unconfigured Rollbar api token) is NoMethodError: undefined method 'id' for {}:Hash.

I also tested using Rails's default cookie store. To reproduce, change the last portions of config/initializers/session_store:

Rails.application.config.session_store :cookie_store, key: '_rollbar_session_repro_session'

Rails.application.middleware.insert_before(
  ActionDispatch::Session::CookieStore,
  WarningMiddleware
)

In this case, the error is undefined method '[]=' for nil:NilClass, which is caused by attempting to access a non-lazily initialized rack.session.options key (mostly unrelated to the other error, but a result of the same order-of-operations issue).

[rokob]

I would almost argue this is buggy behaviour on the part of both Rack and ActionDispatch. The stacktrace using the plain cookie store:

rack (1.5.5) lib/rack/session/abstract/id.rb:289:in `current_session_id'
rack (1.5.5) lib/rack/session/abstract/id.rb:272:in `load_session'
actionpack (4.1.16) lib/action_dispatch/middleware/session/abstract_store.rb:43:in `block in load_session'
actionpack (4.1.16) lib/action_dispatch/middleware/session/abstract_store.rb:51:in `stale_session_check!'
actionpack (4.1.16) lib/action_dispatch/middleware/session/abstract_store.rb:43:in `load_session'
actionpack (4.1.16) lib/action_dispatch/request/session.rb:180:in `load!'
actionpack (4.1.16) lib/action_dispatch/request/session.rb:176:in `load_for_write!'
...

Makes me think that actionpack and rack made assumptions they should not have considering the use of inheritance here. The call to load_session in rack assumes that prepare_session has already populated the session key in env with something it knows how to work with. actionpack does not ensure this is the case when it ends up calling through to it's super class.

We can "fix" this on our side by not modifying the environment which is what this PR does, but this is a really shitty thing that actionpack does.

[zvkemp]

I would almost argue this is buggy behaviour on the part of both Rack and ActionDispatch.

Yes, I completely agree. There is a lot of logic in ActionDispatch/Rack that appears to have been intended to mitigate this issue (the whole 'merge original session' logic that pops up in a few places), but it doesn't cover all of the cases (to wit, this PR).

[rokob]

Let's merge this, it is a reasonable fix to a bad situation caused by ActionDispatch and Rack.