Devise: Devise authorize a User and unauthorizes it right after

Created on 6 Jun 2014  Â·  38Comments  Â·  Source: heartcombo/devise

Hello, I'm posting here after over 6 hours going circle

I use rails 4.1.1 with Devise 3.2.4 + mongoid@master.

I have a User signing in properly:

Started POST "/users/sign_in" for 212.194.198.62 at 2014-06-05 15:18:08 +0000
Processing by Devise::SessionsController#create as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"zObTwp85xx+YFcSuY/d4fPcCHp7sDiYvNWlCFjf81gg=", "user"=>{"email"=>"[email protected]", "password"=>"[FILTERED]"}, "commit"=>"Sign in"}

that gets properly redirected to the after_sign_in route:

Redirected to http://www.white.eu.com/dashboard
Completed 302 Found in 1220ms
Started GET "/dashboard" for 212.194.198.62 at 2014-06-05 15:18:09 +0000
Processing by DashboardController#index as HTML

which unauthorizes the User right after:

Completed 401 Unauthorized in 1ms

I've tried enabling / disabling each and every devise option. I have no access control gem (CanCan and such).

I did not override Devise#SessionsController. I removed protect_from_forgery from ApplicationController to be sure that csrf_token gets not in the way.

DashboardController is as simple as it gets:

class DashboardController < ApiController
  helper :all
  def index
  end    
end
class ApiController < ApplicationController
    before_filter :authenticate_user!
end

The request is plain HTML out of Firefox.

The form is the one generated by devise generator to which I simply added the :authenticity_token => form_authenticity_tokenoption (even though protect_from_forgery is off).

The layout is a 4 liners:

<head>
  <%= javascript_include_tag 'application' %>
  <%= csrf_meta_tags %>
</head>
<%= yield %>

and my User model is

class User
  include Mongoid::Document

  devise :database_authenticatable, :registerable,
         :recoverable, :trackable, :validatable,
         :confirmable, :lockable, :timeoutable, :rememberable

## Database authenticatable
  field :email,              :type => String, :default => ''
  field :encrypted_password, :type => String, :default => ''
  ## Recoverable
  field :reset_password_token,   :type => String
  field :reset_password_sent_at, :type => Time
  ## Trackable
  field :sign_in_count,      :type => Integer, :default => 0
  field :current_sign_in_at, :type => Time
  field :last_sign_in_at,    :type => Time
  field :current_sign_in_ip, :type => String
  field :last_sign_in_ip,    :type => String
  ## Confirmable
  field :confirmation_token,   :type => String
  field :confirmed_at,         :type => Time
  field :confirmation_sent_at, :type => Time
  field :unconfirmed_email,    :type => String # Only if using reconfirmable
  ## Rememberable
  field :remember_created_at, type: Time
  ## Lockable
  field :failed_attempts, :type => Integer, :default => 0
  field :unlock_token,    :type => String # Only if unlock strategy is :email or :both
  field :locked_at,       :type => Time
  index({:email => 1}, {:unique => true})
  index({:reset_password_token => 1})
  end

sign_in_count gets properly incremented every time sign_in redirects.

I run out of options/ideas/strength.

Any help is much appreciated.

picture liedergram

Most helpful comment

Aaaaaaaaaaaaaaaaaaaaah! Found it!

config/session_store.rb:

White::Application.config.session_store :cookie_store, { key: '_white_session', :secure => true }

was messing the whole stuff! I changed to:

White::Application.config.session_store :cookie_store, key: '_white_session'

and loggin in works...

picture liedergram on 9 Jun 2014
👍9

All 38 comments

I can think of two things:

  1. It is a Mongoid issue: https://github.com/plataformatec/devise/pull/2882
  2. The user has provided valid credentials but something else is marking the user as invalid/inactive. For example, he has not confirmed his account.

Since there is no way for me to reproduce the error locally, I ask you to kind explore those two possibilities and report back. :)

josevalim picture josevalim on 6 Jun 2014

Hello @josevalim, I've set production log to :debug to get the complete output of mongoid as well as Devise.

I see no error there, and data (email / password / sign_in_count / etc.) get properly updated with the sign up / confirmation / sign in process.

I indeed use a email only signup + choose password in confirmation process as explained in the Wiki.

Here are my User added methods, the rest is copied and paste from Wiki.

class User
 # https://github.com/plataformatec/devise/wiki/How-To:-Override-confirmations-so-users-can-pick-their-own-passwords-as-part-of-confirmation-activation
  def attempt_set_password(params)
    update_attributes({ :password => params[:password], :password_confirmation =>   params[:password_confirmation] })
  end

  def has_no_password?
    self.encrypted_password.blank?
  end

  def only_if_unconfirmed
    pending_any_confirmation{ yield }
  end

  def password_required?
    return false unless persisted?
    !password.nil? || !password_confirmation.nil?
  end

  def password_match?
    self.password == self.password_confirmation
  end

I will go over the confirmation process step by step and report. Thank you once more.

liedergram picture liedergram on 6 Jun 2014

OK, I went over the users stored in database:

raavril14th@avril14th-ubuntu:~/src/white$ rails c -e production
Loading production environment (Rails 4.1.1)
2.1.2 :001 > User.all.map(&:confirmed?)
 => [true, true] 
2.1.2 :002 > User.all.map(&:valid?)
 => [true, true] 
2.1.2 :003 > User.first.method(:confirmed?).source_location
 => ["/home/avril14th/.rvm/gems/ruby-2.1.2/gems/devise-3.2.4/lib/devise/models/confirmable.rb", 87] 
2.1.2 :010 > User.all.map(&:unlock_token?)
 => [false, false] 
2.1.2 :011 > User.all.map(&:valid_for_authentication?)
 => [true, true]

and I see nothing stopping them from being valid or inactive. They seem in great shape. :)

liedergram picture liedergram on 6 Jun 2014

Have you checked the mongoid issue? Maybe we can't serialize / dump the data into session?

josevalim picture josevalim on 6 Jun 2014

@josevalim Yes! I patched my User class with the snippet code from https://github.com/plataformatec/devise/pull/2882. I created / confirmed / tried to log a new user in and still the same error.

Is there any way to get a more verbose :authenticate_user! to know exactly why it unauthorizes?

liedergram picture liedergram on 6 Jun 2014

It doesn't set any flash message nor anything? :( If not, your best option is to debug the failure_app and see what is happening there: https://github.com/plataformatec/devise/blob/master/lib/devise/failure_app.rb#L33

If you are not familiar with debuging, the easy way is to add "pry" to your gemfile, then run bundle open devise and add binding.pry in the method above.

josevalim picture josevalim on 6 Jun 2014

OK, I'm starting to test silly stuffs.

  1. I put Webrick in production (instead of Nginx + unicorn) and problem still occurs.
  2. I removed the :authenticate_user! call and everything works as expected (I get a nil exception when hitting the first call on the current_user object).
  3. We've hacked away an Ajax call that adds CSRF Token in the request header instead of the params. This also fails for same reason (which is normal since csrf check is supposed to be disabled).

Now, to answer your question I also added 

<% flash.each do |key, value| %>
    <div class="alert alert-<%= key %>">
      <a href="#" data-dismiss="alert" class="close">×</a>
      <ul>
        <li>
          <%= value %>
        </li>
      </ul>
    </div>
<% end %>

to my layout.

All views have 

<%= devise_error_messages! %>

and no message shows up. :(
Let me try your failure app., I'll get back to you real quick!!

(BTW: Did I mention that I have a TimeOutApp as my user is :timeoutable, but I guess that has nothing to do with our topic).

liedergram picture liedergram on 6 Jun 2014

@josevalim ok I tried the failure app, here is what I get:

def respond
  if http_auth? # => false
    http_auth
  elsif warden_options[:recall] # => nil
    recall
  else
    redirect # => So we get here
  end
end

I suppose redirect is what kicks me out?!

liedergram picture liedergram on 6 Jun 2014

Yeah, try to call these functions:

https://github.com/plataformatec/devise/blob/master/lib/devise/failure_app.rb#L169-L183

And see what they return. Maybe warden_message can tell what is really happening?

josevalim picture josevalim on 6 Jun 2014

Also, if you want to submit a pull request that adds Rails.logger.debug { ... } with proper information about why the user is not signed in (likely the warden_message value), it would be very welcome!

josevalim picture josevalim on 6 Jun 2014

I'll do anything man if I get this log in to work! :)

Back to it, be right back.

liedergram picture liedergram on 6 Jun 2014

Well,

there we go:

def warden
  env['warden'] #=> "Warden::Proxy:43701280 @config={:default_scope=>:user, :scope_defaults=>{}, :default_strategies=>{:user=>[:rememberable, :database_authenticatable]}, :intercept_401=>false, :failure_app=>TimeoutRedirectionApp}"
end

def warden_options
  env['warden.options'] # => "{:scope=>:user, :action=>"unauthenticated", :attempted_path=>"/dashboard"}"
end

def warden_message
  @message ||= warden.message || warden_options[:message] # => nil
end

def scope
  @scope ||= warden_options[:scope] || Devise.default_scope # => :user
end

def attempted_path
  warden_options[:attempted_path] # => "/dashboard"
end

warden_messageis nil...
/me jumps out the window

liedergram picture liedergram on 6 Jun 2014

:O

Do a puts caller... let's so who/what is calling the failure app and see if we can get some info from there...

josevalim picture josevalim on 6 Jun 2014

puts "Caller is #{caller}":

Caller is: 

 ["/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/abstract_controller/base.rb:189:in `process_action'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/abstract_controller/base.rb:136:in `process'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_controller/metal.rb:195:in `dispatch'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_controller/metal.rb:231:in `block in action'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/bundler/gems/devise-2bde395840b9/lib/devise/failure_app.rb:22:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/bundler/gems/devise-2bde395840b9/lib/devise/failure_app.rb:22:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/warden-1.2.3/lib/warden/manager.rb:130:in `call_failure_app'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/warden-1.2.3/lib/warden/manager.rb:116:in `process_unauthenticated'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/warden-1.2.3/lib/warden/manager.rb:47:in `call'",
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/etag.rb:23:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/conditionalget.rb:25:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/flash.rb:254:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:225:in `context'", 
 "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:220:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/cookies.rb:560:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'", 
 "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/callbacks.rb:82:in `run_callbacks'", 
 "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/remote_ip.rb:76:in `call'", 
 "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'", 
"/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/rack/logger.rb:38:in `call_app'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/rack/logger.rb:20:in `block in call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/tagged_logging.rb:68:in `block in tagged'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/tagged_logging.rb:26:in `tagged'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/tagged_logging.rb:68:in `tagged'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/rack/logger.rb:20:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/actionpack-4.1.1/lib/action_dispatch/middleware/request_id.rb:21:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/methodoverride.rb:21:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/runtime.rb:17:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/cache/strategy/local_cache_middleware.rb:26:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/sendfile.rb:112:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/engine.rb:514:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/application.rb:144:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/content_length.rb:14:in `call'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/connection.rb:86:in `block in pre_process'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/connection.rb:84:in `catch'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/connection.rb:84:in `pre_process'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/connection.rb:53:in `process'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/connection.rb:39:in `receive_data'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run_machine'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/backends/base.rb:73:in `start'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/thin-1.6.2/lib/thin/server.rb:162:in `start'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/handler/thin.rb:16:in `run'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/rack-1.5.2/lib/rack/server.rb:264:in `start'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands/server.rb:69:in `start'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands/commands_tasks.rb:81:in `block in server'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands/commands_tasks.rb:76:in `tap'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands/commands_tasks.rb:76:in `server'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands/commands_tasks.rb:40:in `run_command!'", "/home/avril14th/.rvm/gems/ruby-2.1.2/gems/railties-4.1.1/lib/rails/commands.rb:17:in `<top (required)>'", "/home/avril14th/src/white/bin/rails:21:in `require'", "/home/avril14th/src/white/bin/rails:21:in `<top (required)>'", "-e:1:in `load'", "-e:1:in `<main>'"]
liedergram picture liedergram on 6 Jun 2014

I breakpointed around, I have NO IDEA where to look as I never went that low so please bear with me.

What throws the 401 is line 34 of

https://github.com/hassox/warden/blob/master/lib/warden/manager.rb

That is catch(:warden). This gets hit as soon as the GET "/dashboard" as HTML strikes in.

I breakpointed a little down to see that we get straight to the routes dispatch in which I get lost. :/

We checked that of course our DashboardController#index handles the HTML format (!) which it does. (This we knew since turning Devise off have the request to suceed).

We removed two Middleware which were hit in between (Mongoid::QueryCache and NewRelic) so we know it's not coming from there.

I'll keep breakpointing, any hint would be over nice as I'll have to waste the weekend on this..

liedergram picture liedergram on 6 Jun 2014

OK, one step below: 

https://github.com/rails/rails/blob/4-1-stable/actionpack/lib/action_dispatch/journey/router.rb line 71

is throwing the 401.

Here are my routes (which of course work when Devise is turned off):

  as :user do
    patch '/users/confirmation' => 'confirmations#update', :via => :patch, :as => :update_user_confirmation
  end
  devise_for :users, controllers: { :confirmations => 'confirmations', :registrations => 'registrations' }
liedergram picture liedergram on 6 Jun 2014

You could temporarily remove the catch(:warden) block from warden to let the throw(:warden) pass through. Then we will be able to at least know how called it.

josevalim picture josevalim on 6 Jun 2014

Here it is: I don't know what to check next since authenticate_user! is generated on the fly:

ArgumentError (uncaught throw :warden):
  warden (1.2.3) lib/warden/proxy.rb:128:in `throw'
  warden (1.2.3) lib/warden/proxy.rb:128:in `authenticate!'
  /home/avril14th/.rvm/gems/ruby-2.1.2/bundler/gems/devise-2bde395840b9/lib/devise/controllers/helpers.rb:54:in `authenticate_user!'
  activesupport (4.1.1) lib/active_support/callbacks.rb:424:in `block in make_lambda'
  activesupport (4.1.1) lib/active_support/callbacks.rb:160:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:160:in `block in halting'
  activesupport (4.1.1) lib/active_support/callbacks.rb:166:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:166:in `block in halting'
  activesupport (4.1.1) lib/active_support/callbacks.rb:86:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:86:in `run_callbacks'
liedergram picture liedergram on 7 Jun 2014

Hrm, Rails is probably scrubbing the stacktrace. Can you add: Rails.backtrace_cleaner.remove_silencers! to your config/environment.rb and give it a try to see if we can get more info?

josevalim picture josevalim on 7 Jun 2014

Also, are you using a custom warden strategy? Maybe it is failing and it is not passing any of them messages Devise expects...

josevalim picture josevalim on 7 Jun 2014

But basically what is happening is that there is no user in session and no strategy is kicking in. It could also be related to the session store... anyway, if you have a way to reproduce the error, it would really help because at this point something really fishy is happening.

josevalim picture josevalim on 7 Jun 2014

I'm still on it.

Warden::Strategies._strategies is returning :rememberable and :database_authenticatable.

The funny thing is that I put breakpoint in both of these strategies' authenticate! and none get hit when GET /dashboard is processed. (while database_authenticatable gets hit when doing POST /users/sign_in.

As you say, no strategy is kicking in. I use no custom strategie (and _strategies returns 2 anyway).

Let me try without the silencers, be right back.

liedergram picture liedergram on 7 Jun 2014

Without backtrace silencers (same output):

Redirected to http://localhost:3000/dashboard
Completed 302 Found in 2138ms
Started GET "/dashboard" for 127.0.0.1 at 2014-06-07 17:26:23 +0200
Processing by DashboardController#index as HTML
Completed 500 Internal Server Error in 2ms
FATAL -- : 
ArgumentError (uncaught throw :warden):
  warden (1.2.3) lib/warden/proxy.rb:128:in `throw'
  warden (1.2.3) lib/warden/proxy.rb:128:in `authenticate!'
  devise (3.2.4) lib/devise/controllers/helpers.rb:50:in `authenticate_user!'
  activesupport (4.1.1) lib/active_support/callbacks.rb:424:in `block in make_lambda'
  activesupport (4.1.1) lib/active_support/callbacks.rb:160:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:160:in `block in halting'
  activesupport (4.1.1) lib/active_support/callbacks.rb:166:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:166:in `block in halting'
  activesupport (4.1.1) lib/active_support/callbacks.rb:86:in `call'
  activesupport (4.1.1) lib/active_support/callbacks.rb:86:in `run_callbacks'
  actionpack (4.1.1) lib/abstract_controller/callbacks.rb:19:in `process_action'
  actionpack (4.1.1) lib/action_controller/metal/rescue.rb:29:in `process_action'
  actionpack (4.1.1) lib/action_controller/metal/instrumentation.rb:31:in `block in process_action'
  activesupport (4.1.1) lib/active_support/notifications.rb:159:in `block in instrument'
  activesupport (4.1.1) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  activesupport (4.1.1) lib/active_support/notifications.rb:159:in `instrument'
  actionpack (4.1.1) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
  actionpack (4.1.1) lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
  actionpack (4.1.1) lib/abstract_controller/base.rb:136:in `process'

I'm short of ideas. Still ok to debug until we fix this, we're about to launch our flagship product after nearly two years of dev... :)

(P.S: How does Devise store sessions? between requests if I remove the rememberable strategy?)

Anything I can try?

liedergram picture liedergram on 7 Jun 2014

OK, I've breakpointed some more.

Here is the story:

Started POST "/users/sign_in" for 127.0.0.1 at 2014-06-09 14:42:29 +0200
Processing by Devise::SessionsController#create as HTML

Here, Warden proxy @users array is indeed empty. So it calls rememberable strategy which is non valid (strategy.valid?) since there is no cookie set. It then calls the DatabaseAuthenticatable strategy as this one is valid (strategy.valid? returns true : due to the presence of params in the request, not because of http):

I, [2014-06-09T14:42:29.331391 #6575]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"bp6QEtwDrAWhqoy/VW5XwF1wd1jx5Di4ibrnJbjTlJE=", "user"=>{"email"=>"[email protected]", "password"=>"[FILTERED]", "remember_me"=>"0"}, "commit"=>"Sign in"}

So it queries the user:

MOPED: 137.116.195.86:27017 QUERY        database=white_production collection=users selector={"$query"=>{"email"=>"[email protected]"}, "$orderby"=>{:_id=>1}} flags=[] limit=-1 skip=0 batch_size=nil fields=nil runtime: 179.7399ms

And then it updates it's sign_in_count and other infos:

MOPED: 137.116.195.86:27017 UPDATE       database=white_production collection=users selector={"_id"=>BSON::ObjectId('53918852776869f1ef000000')} update={"$set"=>{"last_sign_in_at"=>2014-06-09 12:39:52 UTC, "current_sign_in_at"=>2014-06-09 12:44:33 UTC, "sign_in_count"=>22}} flags=[]

and redirects to the after_sign_in path:

Redirected to http://localhost:3000/dashboard
Completed 302 Found in 124354ms

Now comes the GET request:

Started GET "/dashboard" for 127.0.0.1 at 2014-06-09 14:44:33 +0200
Processing by DashboardController#index as HTML

and Devise strikes in. Strangely enough (that's the part I don't get) warden proxy @users array is still empty!

So here rememberable strategy strikes in, which is invalid. Next DatabaseAuthenticatable strategy, which is also invalid as it is both invalid for http authentication and the params authentication.

No strategy runs, we're unauthorized:

Completed 401 Unauthorized in 50597ms

So from my understanding, the trouble is that the @users array remains empty between the POST sign_in and the GET dashboard requests. Something broken in that session mechanism, or maybe a wrong setting in rails?!

Any input is welcome.

liedergram picture liedergram on 9 Jun 2014

Can you provide an application that reproduces the error? Maybe you have a custom controller or strategy affecting stuff... It is definitely works on a simple app, so something is messing it up.

josevalim picture josevalim on 9 Jun 2014

It's really hard to tailor down an application to reproduce the error. This app is about 30K lines of code (~10K front, ~10K back, ~10K specs).

I can post concerned controllers and also configuration files though. Would this help?

liedergram picture liedergram on 9 Jun 2014

Aaaaaaaaaaaaaaaaaaaaah! Found it!

config/session_store.rb:

White::Application.config.session_store :cookie_store, { key: '_white_session', :secure => true }

was messing the whole stuff! I changed to:

White::Application.config.session_store :cookie_store, key: '_white_session'

and loggin in works...

liedergram picture liedergram on 9 Jun 2014
👍9

Oh wow. Yeah, if you keep secure: true, you should just access the website with https. You can set config.force_ssl = true to guarantee that.

josevalim picture josevalim on 10 Jun 2014

Good to know. I hope there was a warning somewhere about that, or at least that the CookieJar was not storing any session...

liedergram picture liedergram on 11 Jun 2014

@muichkine : you saved me a whole bunch of time. :)

gocoolkris picture gocoolkris on 25 Apr 2016

@muichkine , @josevalim

I am using rails 4.2.6 and devise 3.4.1 and all the remaining things are same, Still can't login after successfully sign in, like after sign in got the "Completed 401 Unauthorized in 1ms" when move to dashboard controller.

I have "Rails.application.config.session_store :active_record_store, key: 'key_name', domain: :all" setting into session_store.rb file.

What should I do with above file, can you please suggest me something on this.

Thanks in advance !!

NiteshKaradwall picture NiteshKaradwall on 27 May 2016
👍1

@NiteshKaradwall
Any updates on that? I'm facing the same problem and can't get rid of that

marcelamiach picture marcelamiach on 24 Apr 2017

Hey @NiteshKaradwall, did you ever solve this? I am having the same issue

brobertsaz picture brobertsaz on 2 Feb 2018

Thank you so much @muichkine You saved my Time!
I have exact same issue, and I am using

Rails 4.2.7.1 & Devise 3.5.10 With MongoDB, MongoId 5.0.2

Always After login I am getting

ActionController::InvalidAuthenticityToken in SessionsController#create
ActionController::InvalidAuthenticityToken

and I have

before_filter :authenticate_user!

in my dashboard_controller.rb

And session_store.rb has

Rails.application.config.session_store :cookie_store, key: '_my_appname', secure: true

I changed that into

Rails.application.config.session_store :cookie_store, key: '_my_appname', secure: Rails.env.production?

and it works! Great!

abhilashak picture abhilashak on 25 Apr 2018

I seem to have the exact same problem, however secure: false does not seem to solve it. Any ideas? Seems to only be an issue in Safari...

NielsKSchjoedt picture NielsKSchjoedt on 8 Sep 2018

Looks like we have the same problem here in Chrome / Safari or Firefox.
The sign_in process is alright: a user is found, the session stats are updated but when redirecting after sign_in I got instantly a "Completed 401 Unauthorized".
My session_store.rb is Rails.application.config.session_store :cookie_store, key: '_my_appname'

ThomasSertorio picture ThomasSertorio on 15 Oct 2018

Same problem here, so I just succesfully signed in, and after I tried to get my protected endpoint, it returned "Completed 401 Unauthorized", and redirected me to login screen again, so on.

FikriRNurhidayat picture FikriRNurhidayat on 21 Mar 2019

Okay, I think I found out what was going on in my case. It was actually a user behaviour causing this: https://stackoverflow.com/questions/51917046/devise-some-users-on-ios-keeps-getting-signed-out-when-they-leave-the-browser/55277413#55277413

NielsKSchjoedt picture NielsKSchjoedt on 21 Mar 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

jimiguru picture jimiguru  Â·  36Comments
TheScarfix picture TheScarfix  Â·  23Comments
remomueller picture remomueller  Â·  22Comments
millisami picture millisami  Â·  27Comments
brahmadpk picture brahmadpk  Â·  37Comments