Masquerading sometimes lost

[daveharris]

Hi,

I am using devise_masquerade v0.6.5 and devise v4.7.1 and pundit v1.1.0. I acknowledge that v0.6.5 is old but I'm wondering whether v1.2.0 will fix it, or even how I would track this bug down. I am not doing anything different or abnormal and the default configuration.

Sometimes (I haven't been able to find a repeatable set of steps) where once I've masqueraded as a user, sometime later the app looses the masquerading part and I'm then logged in directly as the user I was masquerading.

It happened to me on my phone this morning:

1. I (as an admin) masqueraded into a normal user account
2. I used the application as the user account
3. I locked my phone and did something else for a few mins
4. I picked up my phone and Safari refreshed the page (maybe due to memory usage or something)
5. I noticed that I was logged in directly as the user account

This happens to me (and other admins) on desktop as well, but only occasionally, non-repeatable.

I feel like this is an issue with something in the cookie expiring, but clearly the Devise cookie isn't expired otherwise I would no longer be logged in as the user account.

Can you think of a scenario or codepath where session["warden.user.user.key"] gets set to session["devise_masquerade_user"]? I see there are a few other bugs (#33, #63) floating around in this area, but aren't exactly the same.

Thanks for your time and for much such a useful gem.

If there is any more information I can provide or something to log then please let me know!

[oivoodoo]

Hi @daveharris .

it's pretty good steps for reproducing the problem, I will try to find the time the next following days. As you mentioned I have 2 more issues in queue as well.

Thank you for reporting the issue!

[daveharris]

That would be amazing thanks!

[daveharris]

@oivoodoo Do you think that this has been fixed in one of the latest versions (I’m still back on v0.6.5)?

[pjmurray]

@daveharris Bumping as I have recently upgraded and am still seeing this issue.

[oivoodoo]

@pjmurray Going to check it during the day the possible problems, sorry for long, long way to come back to the issue :)

[daveharris]

I would love to know the cause. I somehow kinda suspected it was because the cookie expires, or maybe she overflow issue but I have no basis for that

[brent-yearone]

I'm also seeing this problem. It's intermittent, and I've not been able to reproduce it in my dev environment; it only happens in staging/production.

What I've observed is that sometimes when I masquerade, the masquerade is lost immediately -- when I click the masquerade link (that is processed by the Devise::MasqueradesController), as soon as I'm redirected to the next page I'm logged in as the user I'm masquerading as, and the app state has forgotten that I'm me.

I've put in some logging code in my ApplicationController, that looks like this:

  prepend_before_action :authenticate_user! # Invoke Devise
  before_action :masquerade_user! # Invoke Devise Masquerade

  private def masquerade_user!
    result = super
    if user_signed_in?
      log_values = {
        current_user: "User ##{current_user.id} (#{current_user.name})",
        user_helper_session_key: user_helper_session_key,
        'cache[user_helper_session_key]': Rails.cache.exist?(user_helper_session_key).inspect,
        user_masquerade?: user_masquerade?.inspect,
        user_masquerade_owner: user_masquerade_owner.present? ? "User ##{user_masquerade_owner.id} (#{user_masquerade_owner.name})" : 'none',
      }
      Rails.logger.warn("*** Masquerade call #{log_values}")
    end
    result
  end

This morning the issue happened again, and the log helpfully gave me this:

*** Masquerade call {:current_user=>"User #294 ([name redacted])", :user_helper_session_key=>"devise_masquerade_user_294_965c4f55-74b0-4739-9c8c-40c0699b074f", :"cache[user_helper_session_key]"=>"false", :user_masquerade?=>"false", :user_masquerade_owner=>"none"}

As you can see, the masquerade owner is gone.

Across subsequent requests, the user_helper_session_key remains constant, which is good. What's bad is that the key isn't set in the cache.

So, it looks to me like the key isn't getting written to the cache at all. My cache store is Redis, and although I've got Redis set up to evict old keys, the instance isn't even close to being full, and I'm not seeing any other cache-related issues, so I don't think Redis is the culprit.

The net result for us is (1) we're out of security compliance. (2) Because the masquerade owner is lost, I can't prevent our staff from modifying the user's state in inappropriate ways (eg, if you're masquerading, I block user profile updates, and I suppress a lot of usage telemetry).

Any help would be appreciated!

[daveharris]

@brent-yearone I wish I offer more insight, however I just have a few things to add.

When I was upgrading from Rails 5 to 6 I attempted to upgrade devise_masquerade from v0.6.5 to v1.x.x. Reading the release notes of the changes I noticed that there were quite a few changes to the caching which got me thinking ...

We haven't really had much need for caching (it's important that everything is up to date in terms of stock units etc) and so the default cache store in production is :file_store. Given we have multiple servers, what my problem could've been was that the key only existed in the cache on one server and not the other. However, I have no proof of this and given it was very infrequent it doesn't really make sense as requests are load balanced via round-robin.

I see that you are using Redis so this almost certainly isn't the issue for you, but thought it might give you some more context perhaps. I never saw the masquerading fail immediately though. I most often saw it when I had been logged in on my phone for a while but not used it. That's why I thought mobile Safari might've cleaned something up when it was hibernated. But who knows .... Not I that's for sure!

After running into a few issues getting devise_masquerade to work with Rails 6 (things like routes being named weirdly and not working at all in the specs), I switched to pretender as we use a bunch of other gems by Andrew Kane and it's very simple so you have to do more, but it's also less magical/more predictable when stuff doesn't work. WMMY!

It's also worth noting that pretender does have an issue where editing the masquerading user's account then logs you in directly as them - exactly what you are wanting to avoid. It's actually an issue in Devise, not pretender and there is a work-around, see https://github.com/ankane/pretender/issues/5. Other than that, it works as a charm, and was an almost drop-in replacement because I had written helpers like ApplicationController#masquerading_user so I could just change the implementation of that method.

Sorry I can't help your actual problem. I'd love to know that the real issue is.

[brent-yearone]

@daveharris You're totally right to suspect the :file_store cache! I would have done the same in your situation. But yeah, with Redis in the mix, I'm certain it's not server-dependent for me. To be perfectly honest, I have seen the bad behavior immediately, but I've also seen it after a delay (although that's much more rare). I suspect that we may not stay masquerading long enough to trigger any time-based effects.

I didn't know about pretender! I'll take a look and see -- that may do the trick for us, especially since the pretend will work in ActionCable channels as well as ActionController requests. Thanks for the tip!

[oivoodoo]

Hi @brent-yearone and @daveharris

First of all, thank you for the pretty detailed discussions. it's really valuable to research the problem, I will do my best to find the time for this issue this month.

Also going to mention why cache was introduced https://github.com/oivoodoo/devise_masquerade/issues/83 and PR https://github.com/oivoodoo/devise_masquerade/pull/76 . Storing there the user details to skip the ways to modify the session. it was so long time ago that I could be wrong about it. But please check security issue. pretender is using session. if you are ok with the issue above I can make the session is optionable way and skip cache if you decide to set it in config for devise_masquerade.

Let me know what you think about it.

Thank you again!

[brent-yearone]

I suspect that the switch to using Rails.cache isn't the main driver of the bug. It might have been an enabler though. :) I say that because in my app, I'm using Redis for the session store, and for the cache store. So either way, the data is moving in & out of Redis. The security issue in #83 was only a problem for anybody using a cookie-based session store, where a malicious user could modify the cookie. To be fair, though, the vulnerability requires the secret_key_base to have leaked, which means you've already been severely compromised. At that point, the masquerade vulnerability is fairly small potatoes.

I'm of two minds about the configuration switch you're talking about. Devs have already decided how to cache, and how to session, and that's really the configuration decision that matters. On the other hand, depending on the cache configuration and the usage patterns, cache data can't be relied on, since many caches evict data based on usage. In my case, both the session & the cache are in Redis, but I've got two Redis instances and they're tuned differently -- the caching instance is more aggressive about evicting unused keys, but the session Redis expires based on age alone (and has different alerting thresholds so we can know before we run out of space).

Maybe I just made the argument in favor of the config switch? As the gem author, you can't know in advance where the masquerade data will be best stored, but as the app dev I should know that. So if you create the config switch, I can decide where to put the data to be the most reliable & secure. You could default to using the cache, and let devs decide to put the data in the session instead, but only if they're not using the cookie store since that's where the vulnerability sits. I'd be ok with that, since generally speaking :cookie_store is the worst session store.

[oivoodoo]

@brent-yearone now it's possible to choose session or cache :

    # optional, default: masquerade_storage_method = :session
    # values: :session, :cache
    Devise.masquerade_storage_method = :session

[brent-yearone]

Beautiful. Thank you!