Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Rails Can't verify CSRF token authenticity on Heroku/production only

The app works OK locally in both development and production mode, but once deployed on Heroku, the CSRF validation fails. This is a vanilla, non-ajax request.

Locally, I run in producion mode with

RAILS_ENV=production heroku local -e production

I wanted to make sure that this is the real issue so I disabled the authenticity token verification and the Heroku version worked, too.

Update: Here's my config:

# session_store.rb:
Hlresponse::Application.config.session_store :cookie_store, key: '_hlresponse_session', domain: :all

# Environment:

$ heroku config:set MIN_THREADS=1 MAX_THREADS=1

# Procfile:

web: bundle exec puma -C config/puma.rb

# config.ru:

require ::File.expand_path('../config/environment',  __FILE__)
run Rails.application

# puma.rb:

workers Integer(ENV['WEB_CONCURRENCY'] || 2)
threads_count = Integer(ENV['MAX_THREADS'] || 5)
threads threads_count, threads_count

preload_app!

rackup      DefaultRackup
port        ENV['PORT']     || 3000
environment ENV['RACK_ENV'] || 'development'

on_worker_boot do
  # Worker specific setup for Rails 4.1+
  # See: https://devcenter.heroku.com/articles/deploying-rails-applications-with-the-puma-web-server#on-worker-boot
  ActiveRecord::Base.establish_connection
end

Here are two sets of logs, one without the error (and verification disabled), and another with the verification enabled, with error. Any idea on how to approach this?

With verify_authenticity_token disabled (skip_before_action :verify_authenticity_token)

Jun 05 23:46:58 hlevents app/web.1:  Started POST "/admin/snippets" for 64.69.46.217 at 2015-06-06 06:46:57 +0000 
Jun 05 23:46:58 hlevents heroku/router:  at=info method=POST path="/admin/snippets" host=hlevents.herokuapp.com request_id=5de24f22-13bb-43ff-a8f1-d65efd08b879 fwd="64.69.46.217" dyno=web.1 connect=0ms service=15ms status=302 bytes=1047 
Jun 05 23:46:58 hlevents app/web.1:  Processing by SnippetsController#create as HTML 
Jun 05 23:46:58 hlevents app/web.1:  Processing by SnippetsController#index as HTML 
Jun 05 23:46:58 hlevents app/web.1:    Rendered shared/admin/_include_bootstrap.html.erb (0.1ms) 
Jun 05 23:46:58 hlevents app/web.1:    Rendered shared/admin/_breadcrumbs.html.erb (0.2ms) 
Jun 05 23:46:58 hlevents app/web.1:    Parameters: {"utf8"=>"✓", "authenticity_token"=>"oPdNjND12fwYrx8YdxhdQLqs67JbX8MkNxyGGj8NS2DwxHxe5HK2Fl+FdOSEs4t73ISoGPgF24YeZphwOmsNGg==", "snippet"=>{"name"=>"test2", "draft_content"=>"test2"}, "save_as_draft"=>"true", "commit"=>"Create Snippet"} 
Jun 05 23:46:58 hlevents app/web.1:  Redirected to https://hlevents.herokuapp.com/admin/snippets 
Jun 05 23:46:58 hlevents app/web.1:  Completed 302 Found in 10ms (ActiveRecord: 4.0ms) 
Jun 05 23:46:58 hlevents app/web.1:  Started GET "/admin/snippets" for 64.69.46.217 at 2015-06-06 06:46:58 +0000 
Jun 05 23:46:58 hlevents app/web.1:    Rendered snippets/index.html.erb within layouts/application (3.9ms) 
Jun 05 23:46:58 hlevents app/web.1:    Rendered shared/admin/_menu.html.erb (0.4ms) 
Jun 05 23:46:58 hlevents app/web.1:  Completed 200 OK in 8ms (Views: 5.4ms | ActiveRecord: 1.2ms) 

With verify_authenticity_token enabled:

Jun 05 23:49:38 hlevents app/web.1:  Started POST "/admin/snippets" for 64.69.46.217 at 2015-06-06 06:49:38 +0000 
Jun 05 23:49:38 hlevents app/web.1:  Processing by SnippetsController#create as HTML 
Jun 05 23:49:38 hlevents app/web.1:  Can't verify CSRF token authenticity 
Jun 05 23:49:38 hlevents app/web.1:  ActionController::InvalidAuthenticityToken (ActionController::InvalidAuthenticityToken): 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/request_forgery_protection.rb:181:in `handle_unverified_request' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/request_forgery_protection.rb:209:in `handle_unverified_request' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/request_forgery_protection.rb:204:in `verify_authenticity_token' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:164:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:164:in `block in halting' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:504:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:504:in `block in call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:504:in `each' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:504:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:92:in `_run_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:776:in `_run_process_action_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:81:in `run_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/abstract_controller/callbacks.rb:19:in `process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/rescue.rb:29:in `process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/notifications.rb:164:in `block in instrument' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/notifications.rb:164:in `instrument' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activerecord-4.2.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/abstract_controller/base.rb:137:in `process' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionview-4.2.1/lib/action_view/rendering.rb:30:in `process' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal.rb:196:in `dispatch' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_controller/metal.rb:237:in `block in action' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/routing/route_set.rb:74:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/journey/router.rb:30:in `each' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/journey/router.rb:30:in `serve' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/routing/route_set.rb:819:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/etag.rb:24:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/conditionalget.rb:38:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/head.rb:13:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/flash.rb:260:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/session/abstract/id.rb:225:in `context' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/session/abstract/id.rb:220:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activerecord-4.2.1/lib/active_record/query_cache.rb:36:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:649:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:88:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:88:in `_run_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:776:in `_run_call_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:81:in `run_callbacks' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/railties-4.2.1/lib/rails/rack/logger.rb:38:in `call_app' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/railties-4.2.1/lib/rails/rack/logger.rb:20:in `block in call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:68:in `block in tagged' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:26:in `tagged' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:68:in `tagged' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/railties-4.2.1/lib/rails/rack/logger.rb:20:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/methodoverride.rb:22:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/runtime.rb:18:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    Parameters: {"utf8"=>"✓", "authenticity_token"=>"g0mFZ2tEDMvvSiq3FeIUPFTWiwi8N4LO4cs81PkohjoesgtJgGnQ6I7x+L4kwgMFoqHQHYfqQeznMQduOBzgmQ==", "snippet"=>{"name"=>"test3", "draft_content"=>"test3"}, "save_as_draft"=>"true", "commit"=>"Create Snippet"} 
Jun 05 23:49:38 hlevents app/web.1:  Completed 422 Unprocessable Entity in 1ms (ActiveRecord: 0.0ms) 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/activesupport-4.2.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/actionpack-4.2.1/lib/action_dispatch/middleware/static.rb:113:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/rack-1.6.0/lib/rack/sendfile.rb:113:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/railties-4.2.1/lib/rails/engine.rb:518:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/railties-4.2.1/lib/rails/application.rb:164:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/configuration.rb:51:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/server.rb:507:in `handle_request' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/server.rb:375:in `process_client' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/server.rb:262:in `block in run' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/thread_pool.rb:104:in `call' 
Jun 05 23:49:38 hlevents app/web.1:    vendor/bundle/ruby/2.2.0/gems/puma-2.11.3/lib/puma/thread_pool.rb:104:in `block in spawn_thread' 
Jun 05 23:49:38 hlevents heroku/router:  at=info method=GET path="/favicon.ico" host=hlevents.herokuapp.com request_id=c0616b75-9fb0-4ee0-990d-52f2a34333f2 fwd="64.69.46.217" dyno=web.1 connect=0ms service=5ms status=200 
like image 845
aaandre Avatar asked Oct 20 '22 10:10

aaandre


1 Answers

The issue was with domain: :all in the :cookie_store config.

Hlresponse::Application.config.session_store :cookie_store, key: '_hlresponse_session', domain: :all

I removed it and the cookies reappeared.

Hlresponse::Application.config.session_store :cookie_store, key: '_hlresponse_session'

I will, however, need to have this setting on as I will be using multiple subdomains. I will wait until I set up the custom domain on Heroku and see if it works again. I am wondering if Heroku makes an effort to disable multi-subdomain cookies on their herokuapp.com domain...

like image 86
aaandre Avatar answered Oct 22 '22 02:10

aaandre