InvalidAuthenticityToken

rubyonrails-talk
1

About 50-100 times a day I am getting the following error on my site:

ActionController::InvalidAuthenticityToken occurred in session#create

ActionController::InvalidAuthenticityToken /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/request_forgery_protection.rb:86:in `verify_authenticity_token’

When people try to login in. This does not happen to everyone but it happens to enough people. Both IE and Firefox users.

Has anyone every encountered this problem before?

I am banging my head against the table over this one.

2

I am using the cookie session store if that helps.

3

from the source:

* is the format restricted? By default, only HTML and AJAX requests are checked. * is it a GET request? Gets should be safe and idempotent * Does the form_authenticity_token match the given _token value from the params?

maybe you dont meet one of these conditions for some reason or another

4 
I spoke to a couple people who are running into this problem and they are using the form on the website to login just like everyone else.

It is a post request: <form action="/session"method=“post”>

How do I check that the form_authenticity_token matches the given _token value?

What makes this weird is 95% of people can get in no problem what so ever. It is some of the people some of the time. That is what is confusing? Is is where I set my session values?

Here is session#create:

def create

@user = User.authenticate(params[:nickname], params[:password])

if @user

set_user_session(@user)

@user.set_last_logged_in_to_now

redirect_to session[:return_to].nil? ? home_path : session[:return_to]

else

flash[:error] = "Hmmm, we were not able to find you. You sure you

entered your nickame and password correctly?"

redirect_to root_path

end

end

Does this help?

5

Every stupid time this happened to me it was because I cached the login form using page_caching or some other caching mechanism. You can tell protect_from_forgery to ignore certain actions if that’s what’s happening to you.

6

I am not caching either what so ever. So it is not caching… unless Rails does caching for me by default I should know about! :slight_smile:

Can it be the redirect after the setting of session variables? What can it be? It is driving me and my members crazy.

7

It is defenitely not the redirect since the explosion occurs on the validation of the token against the session token, you should see that from your stack trace... . At this point I am more inclined to go with the caching...

8

I am not doing any caching what so ever unless Rails 2 and 2.1 did caching out of the box.

The stack trace only gives me the only value… not the other.

Any other suggestions? :frowning: Any fixes? :frowning:

9

I ran out of ideas... sorry

10

I am not doing any caching what so ever unless Rails 2 and 2.1 did
caching out of the box.

The stack trace only gives me the only value... not the other.

Any other suggestions? :frowning: Any fixes? :frowning:

Do you reset the session on login? If you do reset the session and if
the user later hits the back button and logs in again then they will
be logging in from the browser's cached copy of the login page (ie
with the old authenticity token)

Fred

11

Big MAYBE:

If you reuse the session_key or secret from another project by copy/pasting this part in environment.rb

Rails::Initializer.run do |config|   config.action_controller.session = {     :session_key => '_something_session',     :secret => 'somethinggoeshere'   } end

Even if later you change it, some of the stuff seems to stick and you get messed up sessions for every user who may have used the other project too or your new project during the time it was using the old combination of secret/key.

Make sure, session_key and secret are unique, then clear the private data (cookies, stored passwords, authenticated session, everything)

This is only a very rough guess, but it may fit with the fact, that only some of your customers have this trouble.

12

No I do not. The person comes straight to the page. Trys to login and boom… gets an InvalidAuthenticityToken… are any parts of the token stored in the cookie store? This does not happen to everyone just some people.

13

No I do not. The person comes straight to the page. Trys to login
and boom... gets an InvalidAuthenticityToken... are any parts of the
token stored in the cookie store? This does not happen to everyone
just some people.

The value which gets hashed to produce the token is stored in the
session (ie in the cookie).

Fred

14

I have no clue why but maybe it is truncated in the cookie and ends up not matching.

At a maximum this is what I store in a session:

session[:return_to] = request.env[‘REQUEST_PATH’] session[:user] = user.id

session[:nickname] = user.nickname

session[:sex] = user.sex

session[:country_id] = user.country_id

session[:administrative_area_id] = user.administrative_area_id

and flash notices…

Maybe I need to change session storage?

15

I have no clue why but maybe it is truncated in the cookie and ends
up not matching.

An exception should be raised if that happens.

At a maximum this is what I store in a session:

session[:return_to] = request.env['REQUEST_PATH'] session[:user] = user.id session[:nickname] = user.nickname session[:sex] = user.sex session[:country_id] = user.country_id session[:administrative_area_id] = user.administrative_area_id and flash notices...

Maybe I need to change session storage?

You could give it a go, but I doubt it will change much. Have you glanced through your log files to see if there;s anything
abnormal or unusual about the people who are affected? There are race
conditions with sessions if users have more than one request, is that
a possibility?

Fred

16

Not from what I can tell. Can you give me any examples that would cause race conditions? Double clicking login?

Also, I have seen it happen in front of me, not by me though, and the person did not do anything unusual from what I could tell.

hmmm…

17

Not from what I can tell. Can you give me any examples that would
cause race conditions? Double clicking login?

For example if you load the page with the login box simultaneously
(and you don't yet have a session cookie) then you'll get two entirely
separate session cookies or if a page fired two ajax requests that
happened to overlap. I know there are some tools (virus scanners, 'web
accelerators') that preemptively load pages before you click on the
link, could be a factor

Other than that I can't think of anything better than finding an
example where it did happen, pull all the requests from that ip
address from your log file and go over it with a fine comb.

If you are using the cookie store, session ids look like

BAh7BiIKZmxhc2hJQzonQWN0aW9uQ29udHJvbGxlcjo6Rmxhc2g6OkZsYXNo %0ASGFzaHsABjoKQHVzZWR7AA%3D%3D-- ebdc89d60a4349db4222e46665474e561b7a230b

if you take the first portion, you can extract what was in their
session:

Marshal .load (CGI .unescape ( "BAh7BiIKZmxhc2hJQzonQWN0aW9uQ29udHJvbGxlcjo6Rmxhc2g6OkZsYXNo %0ASGFzaHsABjoKQHVzZWR7AA%3D%3D").unpack('m*').first) => {"flash"=>{}}

So I had an empty session with just the flash. I'd probably write a script that would munch through the log files
and print each request from the person in question along with what was
in the session and try and workout what happened.

Fred

18

I have included the backtrace if that helps:

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/request_forgery_protection.rb:86:in `verify_authenticity_token’

/opt/local/lib/ruby/gems/1.8/gems/activesupport-2.1.0/lib/active_support/callbacks.rb:173:in send' /opt/local/lib/ruby/gems/1.8/gems/activesupport-2.1.0/lib/active_support/callbacks.rb:173:in evaluate_method’

/opt/local/lib/ruby/gems/1.8/gems/activesupport-2.1.0/lib/active_support/callbacks.rb:161:in call' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/filters.rb:430:in call’ /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/filters.rb:592:in `run_before_filters’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/filters.rb:578:in call_filters' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/filters.rb:573:in perform_action_without_benchmark’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/benchmarking.rb:68:in perform_action_without_rescue' /opt/local/lib/ruby/1.8/benchmark.rb:293:in measure’ /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/benchmarking.rb:68:in `perform_action_without_rescue’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/rescue.rb:201:in perform_action_without_caching' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/caching/sql_cache.rb:13:in perform_action_without_newrelic_trace’

/opt/local/lib/ruby/gems/1.8/gems/activerecord-2.1.0/lib/active_record/connection_adapters/abstract/query_cache.rb:33:in cache' /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.1.0/lib/active_record/query_cache.rb:8:in cache’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/caching/sql_cache.rb:12:in perform_action_without_newrelic_trace' [RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/instrumentation/action_controller.rb:25:in perform_action’

[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/method_tracer.rb:33:in trace_method_execution' [RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/instrumentation/action_controller.rb:20:in perform_action’

[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/method_tracer.rb:33:in trace_method_execution' [RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/instrumentation/action_controller.rb:14:in perform_action’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/base.rb:529:in send' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/base.rb:529:in process_without_filters’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/filters.rb:569:in process_without_session_management_support' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/session_management.rb:130:in process’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/base.rb:389:in process' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:149:in handle_request’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:107:in dispatch' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:104:in synchronize’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:104:in dispatch' /opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:120:in dispatch_cgi’

/opt/local/lib/ruby/gems/1.8/gems/actionpack-2.1.0/lib/action_controller/dispatcher.rb:35:in dispatch_without_trace_Rails_HTTP_Dispatch' [RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/method_tracer.rb:99:in dispatch’

[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/method_tracer.rb:33:in trace_method_execution' [RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/newrelic/agent/method_tracer.rb:98:in dispatch’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/rails.rb:76:in `process’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/rails.rb:74:in synchronize' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/rails.rb:74:in process’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:159:in `process_client’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:158:in each' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:158:in process_client’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:285:in `run’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:285:in initialize' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:285:in new’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:285:in `run’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:268:in initialize' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:268:in new’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel.rb:268:in `run’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/configurator.rb:282:in run' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/configurator.rb:281:in each’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/configurator.rb:281:in `run’

/opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/bin/mongrel_rails:128:in run' /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/lib/mongrel/command.rb:212:in run’ /opt/local/lib/ruby/gems/1.8/gems/mongrel-1.1.4/bin/mongrel_rails:281

/opt/local/bin/mongrel_rails:19:in `load’ /opt/local/bin/mongrel_rails:19

19

Here is what a session looks like from my exceptions notifier:

  • session id: “BAh7BzoMY3NyZl9pZCIlNDNjNWRmNWI4NzE0NTMyZDVhNWQyZWY1ZGQ2NGNh\nZWYiCmZsYXNoSUM6J0FjdGlvbkNvbnRyb2xsZXI6OkZsYXNoOjpGbGFzaEhh\nc2h7AAY6CkB1c2VkewA=–c16141813d11fff60442cef490d015b0c7c39b88”

  • data: {:csrf_id=>“43c5df5b8714532d5a5d2ef5dd64caef”, “flash”=>{}}

I also did what you suggested to double check and there is no _token or authenticity_token in the session_id and just what is written above:

data: {:csrf_id=>“43c5df5b8714532d5a5d2ef5dd64caef”, “flash”=>{}}

Does that make sense? Does that mean the authenticity_token is not being saved to the session to be compared?

20

The authenticity token is never put in the session. The authenticity_token is generated based on session[:crsf_id]. If you can see that value changing unexpectedly then you'll have found the source of the problem

Fred