falcon: Rails/Devise raises an invalid authenticity token on sign-in when running Falcon in HTTPS mode

Migrating from https://github.com/socketry/falcon/issues/24 becuase it’s a different issue.

When I run my Rails application with the default HTTPS binding, attempts to sign in using Devise raises the following error:

Started POST "/users/sign_in" for 127.0.0.1 at 2018-10-24 17:14:29 -0700
Processing by Devise::SessionsController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"QazbNOYd9lDBoUmbHYZusTlYsHbWPyNAuIVnxOnCQWJevfvlvIRYnYXgSSfhYT2PQGf5TR7SPULEx8NgOY5I3A==", "user"=>{"email"=>"[FILTERED]", "password"=>"[FILTERED]", "remember_me"=>"1"}, "commit"=>"Sign In"}
Can't verify CSRF token authenticity.
Completed 422 Unprocessable Entity in 2ms (ActiveRecord: 0.0ms)


Not notifying due to an invalid api_key

ActionController::InvalidAuthenticityToken - ActionController::InvalidAuthenticityToken:

Started POST "/__better_errors/442776df455fb9ec/variables" for 127.0.0.1 at 2018-10-24 17:14:30 -0700
E, [2018-10-24T17:14:30.162837 #25710] ERROR -- #<Async::IO::SSLServer:0x00005570c92b0c98>: Cannot send headers in state: closed (HTTP::Protocol::ProtocolError)
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/http-protocol-0.6.1/lib/http/protocol/http2/stream.rb:170:in `send_headers'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-http-0.34.4/lib/async/http/protocol/http2/request.rb:99:in `send_response'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-http-0.34.4/lib/async/http/protocol/http2/server.rb:69:in `each'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-http-0.34.4/lib/async/http/server.rb:49:in `accept'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-io-1.16.1/lib/async/io/socket.rb:62:in `block in accept_each'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-io-1.16.1/lib/async/io/ssl_socket.rb:124:in `block in accept'
/home/xtagon/.asdf/installs/ruby/2.4.4/lib/ruby/gems/2.4.0/gems/async-1.10.3/lib/async/task.rb:74:in `block in initialize'

This only occurs if I’m using HTTPS with falcon serve, it does not occur when using HTTP with falcon serve nor when running in another server such as Puma. It also does not happen when running Falcon with RACK_HANDLER=falcon rails server.

Rails 5.1.6

Devise 4.5.0

Falcon 0.18.14

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Comments: 61 (41 by maintainers)

Commits related to this issue

Most upvoted comments

Hi, I was facing the same issue over here using Nginx reverse proxy, after a lot of research I found this solution and worked like a charm:

location / { proxy_pass http://app:3000; proxy_set_header Host $http_host; proxy_set_header X-Forwarded-Proto https; }

The headers were the problem in my case, maybe if you could set the headers on falcon start it may solve your problem as well.

Link from were I find a solution: https://stackoverflow.com/questions/54753867/the-change-you-wanted-was-rejected-error-on-all-devise-actions-after-install

@ioquatix I appologize for such a late reply. Unfortunately I haven’t had a chance to test this again and it is no longer a priority. I do appreciate all the help you’ve put into working on this!

And a reproducible case using curl:

Works

$ curl -sik 'https://localhost:9296/' -H 'cookie: foo=foo1; bar=bar2'
HTTP/2 200 
content-length: 4
set-cookie: foo=foo1; path=/; expires=Wed, 16 Oct 2019 21:52:32 -0000
set-cookie: bar=bar2; path=/; expires=Wed, 16 Oct 2019 21:52:32 -0000

Test

Falcon output:

Request for /...
Cookies from env:
  - cookie: "foo=foo1; bar=bar2"
Cookies from request:
  - foo: "foo1"
  - bar: "bar2"

Fails

$ curl -sik 'https://localhost:9296/' -H 'cookie: foo=foo1' -H 'cookie: bar=bar2'
HTTP/2 200 
content-length: 4
set-cookie: foo=foo1; path=/; expires=Wed, 16 Oct 2019 21:53:53 -0000
set-cookie: bar=bar2; path=/; expires=Wed, 16 Oct 2019 21:53:53 -0000

Test

Falcon output:

Request for /...
Cookies from env:
  - cookie: "foo=foo1"
  - cookie: "bar=bar2"
Cookies from request:
  - foo: "foo1\nbar=bar2"

It seems to be an issue with multiple headers and how they’re passed up the chain. Falcon joins them with \n, but Rack::Utils.parse_cookies_header uses ;, as it’s delimiters.

Here is an even simpler reproducible case:

config.ru

#!/usr/bin/env rackup

class RackApp
  def initialize(app)
    @app = app
  end

  def call(env)
    puts "\nRequest for #{env["REQUEST_URI"]}..."
		puts "Cookies from env:"
    env["async.http.request"].headers.each { |k,v| puts "  - #{k}: #{v.inspect}" if k == 'cookie' }
    
    puts "Cookies from request:"
    request = Rack::Request.new(env)
    request.cookies.each { |k, v| puts "  - #{k}: #{v.inspect}" }
    
    response = Rack::Response.new ["Test"], 200, {}
    response.set_cookie("foo", {:value => "foo1", :path => "/", :expires => Time.now+24*60*60})
    response.set_cookie("bar", {:value => "bar2", :path => "/", :expires => Time.now+24*60*60})
    response.finish
  end
end

use RackApp

run lambda { |env| [404, {}, []] }

Run it as falcon --bind https://localhost:9296/ and open https://localhost:9296/ in FireFox or Chromium. Load the page, then reload the page.

The output looks like:

Request for /...
Cookies from env:
  - cookie: "foo=foo1"
  - cookie: "bar=bar2"
Cookies from request:
  - foo: "foo1\nbar=bar2"

Seems that when making a new Rack::Request.new(env) it munges the cookies into one value.

I think I can add some context, as well as relatively easily reproduce the scenario.

Firstly to reproduce:

  1. Open an incognito window to ensure we have a blank state
  2. Request a page served by Falcon that sets a cookie. E.g. a simple Utopia app that sets rack.session.encrypted. The contents of request.cookies is e.g. {"rack.session.encrypted"=>"QB....YLP\n"}
  3. In the developer console run the following: document.cookie = "foobar=1234; path=/; secure"
  4. Reload the page. The contents of request.cookies is now {"rack.session.encrypted"=>"QB....YLP\n\nfoobar=1234"}

Notice how the second cookie is appended to the first? If we inspect request.env we can see the cookies mutating through the stack:

> request.env
=> {"rack.version"=>[2, 0, 0],
 "async.http.request"=>
  #<Async::HTTP::Protocol::HTTP2::Request:0x00007f36b50c6988
   @authority="localhost:9292",
   @body=nil,
   @headers=
    #<Protocol::HTTP::Headers [["cache-control", "max-age=0"], ["dnt", "1"], ["upgrade-insecure-requests", "1"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/77.0.3865.90 Chrome/77.0.3865.90 Safari/537.36"], ["sec-fetch-mode", "navigate"], ["sec-fetch-user", "?1"], ["accept", "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3"], ["sec-fetch-site", "none"], ["accept-encoding", "gzip, deflate, br"], ["accept-language", "en-US,en;q=0.9"], ["cookie", "rack.session.encrypted=QB...YLP%0A"], ["cookie", "foobar=1234"]]>,
...
 "HTTP_COOKIE"=>
  "rack.session.encrypted=QB...YLP%0A\nfoobar=1234",
...
 "rack.request.cookie_hash"=>
  {"rack.session.encrypted"=>
    "QB...YLP\n\nfoobar=1234"},
 "rack.request.cookie_string"=>
  "rack.session.encrypted=QB...YLP%0A\nfoobar=1234"}

If you look at the verbose logs above, you can see something fishy with the cookies. E.g. from the Chrome log where there are multiple cookies present:

GET /favicon.ico HTTP/2.0 ... "cookie"=>["intercom-lou-abcd1234=1", ["remember_user_token=W1siN2RjOWRmY2UtMDMyNS00NTRjLWFjMTUtZDdiZTUwMzRiMDM0Il0sIiQyYSQxMCRFLmd5U3Mxd1kuMXFOZVowTWdGZkVlIiwiMTU0ODI3Njc4MC4yOTI4MTM4Il0%3D--27afafa7d199c9a1ec3b9ae0a4f2a2acd3f09b3d"], ["__profilin=p%3Dt"], ["_plic_session=Z2xLT2h6QWVTRHlzQWs5bkUrTXBObEpOblMwbVEzQ0NVMUdBczZ2K2xZeFR4aUtMUmlZL1U4TEFoNkF1Z05KUGxSeWdqaTVoL05ZSFU1OStkMjVKZkljNjhINXdsQjhKbFBWSXZLVENwVzFBTk1HTm5JQlZNdXhTOG13NWhvQ0JCVnBxR3dzd2RMSVlYWEhKdjk5dWxjdlhDYkhwamppMGE4TS9BcldQZVdOdlo4M0RaeFA1Ky9qZVdQZHNETldDWUJSR3JOOXl4aG5yb2dDZ0JKYVh4TVFRMW1JWmlQMVNOMEhIVGFZNDIwNGpJWTBja3BpN0l2azd5TUJKTUFwYmc4R3RrUmJuTm5WVmhnWGtScHQvMFAvODNnME95cjB1b1ZtNzJQbENDcVE9LS1UOVYyNlNFV2IyMit5dXNtdTRvcndRPT0%3D--4ecce412e99fbdc84681f605fe32d6795458a911"], ["_falcon_issue29_session=RmhWTVFzM0llaElJclNKNlFIbUczMzhveVZha2tZQnM4bG9oZUVXOVYrSHE3S21vOWVaNlhSaXFsbU94bzh0c3h0Q1dHdlFJTEpmMFdlVmV0QTR4OFg5M01rQXZhTFkreGpPMDBjR0psVHRnZ3N6Rzl5c0txdXdZWmFPczRUUC8vempTdVJLc3AzRi8yNHZKckw3ZFBRPT0tLTZJaTBsOWt4SjE4eFZLS0xjYmlGMGc9PQ%3D%3D--09ec64b471898eb262a0c2c27536333818045e63"]]} from #<Addrinfo: 10.0.2.2:62857 TCP>

… whereas the incognito and firefox sessions only have the one cookie so it passes through fine.

Note also how the cookies array is a bit weird: ["intercom-lou-abcd1234=1", ["remember_user_token=W1...]], it’s an array with a string, then arrays of strings. Seems weird?

Hope that provides some insight. It seems to be an issue with > 1 cookie being requested. I can’t reproduce it in curl, so it may be restricted to Chrome only?

Okay, I’ll need to revisit it. Thanks for updating the issue.

This is all really useful information.

I am putting my kids to bed… but later I will review.

I am going to improve the --verbose logging to capture all request and response headers, so that you can do a trace on chrome (working) and Firefox (not working) and we should be able to see some differences.

Yes I would be happy to do that. I’ll try to do it this weekend or early this week. 👍

Sorry, I don’t have a sample, I’ve been testing with a proprietary app.

This may be a Rails issue and not a Falcon issue. I found this, which may be related: https://stackoverflow.com/questions/46793390/https-for-rails-application-invalidauthenticitytoken

However, when I enable config.force_ssl = true and run Falcon, I cannot access the site in the browser. It gives the following error:

The page isn’t redirecting properly

An error occurred during a connection to https://localhost:5100/.

    This problem can sometimes be caused by disabling or refusing to accept cookies.

I think this might be because I’m running in development mode so there isn’t a forwarded header from Nginx (there is no nginx in this scenario).