authenticity_token がパラメータにうめこまれているにもかかわらず CSRF に失敗する

Question

前提

devise ジェムで認証を行っている Rails システムがあります

発生している問題・エラーメッセージ

改修作業のために数ヶ月ぶりに docker 上開発環境で起動して
ホスト上の Chrome から devise が生成するログインフォームにアクセスしてログインしようとしたところ
CSRF 認証に失敗してログインできません

ログイン画面のビューには authenticity_token は埋め込まれていて
Rails のログを見る限りパラメータとしては飛んできています

(トークンを公開することのリスクがわかってないので念のため伏字におきかえてあります)

I, [2020-12-04T06:06:42.750789 #10006]  INFO -- : Started POST "/users/sign_in" for 172.20.1.1 at 2020-12-04 06:06:42 +0000
I, [2020-12-04T06:06:42.774239 #10006]  INFO -- : Cannot render console from 172.20.1.1! Allowed networks: 127.0.0.1, ::1, 127.0.0.0/127.255.255.255
D, [2020-12-04T06:06:42.928436 #10006] DEBUG -- :    (0.8ms)  SET NAMES utf8,  @@SESSION.sql_mode = CONCAT(CONCAT(@@sql_mode, ',STRICT_ALL_TABLES'), ',NO_AUTO_VALUE_ON_ZERO'),  @@SESSION.sql_auto_is_null = 0, @@SESSION.wait_timeout = 2147483
D, [2020-12-04T06:06:42.986806 #10006] DEBUG -- :    (0.5ms)  SELECT `schema_migrations`.`version` FROM `schema_migrations` ORDER BY `schema_migrations`.`version` ASC
I, [2020-12-04T06:06:43.296627 #10006]  INFO -- : Processing by Users::SessionsController#create as HTML
I, [2020-12-04T06:06:43.297852 #10006]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"xxxxx", "user"=>{"email"=>"[e-mail]", "password"=>"[FILTERED]", "remember_me"=>"1"}}
D, [2020-12-04T06:06:43.340060 #10006] DEBUG -- :   User Load (0.3ms)  SELECT  `users`.* FROM `users` WHERE `users`.`email` = '[e-mail]' ORDER BY `users`.`id` ASC LIMIT 1
I, [2020-12-04T06:06:43.341140 #10006]  INFO -- : Completed 401 Unauthorized in 42ms (ActiveRecord: 2.0ms)


I, [2020-12-04T06:06:44.481082 #10006]  INFO -- : Processing by Users::SessionsController#new as HTML
I, [2020-12-04T06:06:44.481563 #10006]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"xxxxx", "user"=>{"email"=>"[e-mail]", "password"=>"[FILTERED]", "remember_me"=>"1"}}
W, [2020-12-04T06:06:44.494312 #10006]  WARN -- : Can't verify CSRF token authenticity.
I, [2020-12-04T06:06:44.495802 #10006]  INFO -- : Completed 422 Unprocessable Entity in 13ms (ActiveRecord: 0.0ms)


F, [2020-12-04T06:06:44.497743 #10006] FATAL -- :
F, [2020-12-04T06:06:44.498244 #10006] FATAL -- : ActionController::InvalidAuthenticityToken (ActionController::InvalidAuthenticityToken):
F, [2020-12-04T06:06:44.498703 #10006] FATAL -- :
F, [2020-12-04T06:06:44.499209 #10006] FATAL -- : actionpack (5.2.4.4) lib/action_controller/metal/request_forgery_protection.rb:211:in `handle_unverified_request'
actionpack (5.2.4.4) lib/action_controller/metal/request_forgery_protection.rb:243:in `handle_unverified_request'
devise (4.7.3) lib/devise/controllers/helpers.rb:255:in `handle_unverified_request'
actionpack (5.2.4.4) lib/action_controller/metal/request_forgery_protection.rb:238:in `verify_authenticity_token'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:426:in `block in make_lambda'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
actionpack (5.2.4.4) lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:199:in `block in halting'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `block in invoke_before'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `each'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `invoke_before'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:131:in `run_callbacks'
actionpack (5.2.4.4) lib/abstract_controller/callbacks.rb:41:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/rescue.rb:22:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
activesupport (5.2.4.4) lib/active_support/notifications.rb:168:in `block in instrument'
activesupport (5.2.4.4) lib/active_support/notifications/instrumenter.rb:23:in `instrument'
activesupport (5.2.4.4) lib/active_support/notifications.rb:168:in `instrument'
actionpack (5.2.4.4) lib/action_controller/metal/instrumentation.rb:32:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
activerecord (5.2.4.4) lib/active_record/railties/controller_runtime.rb:24:in `process_action'
actionpack (5.2.4.4) lib/abstract_controller/base.rb:134:in `process'
actionview (5.2.4.4) lib/action_view/rendering.rb:32:in `process'
actionpack (5.2.4.4) lib/action_controller/metal.rb:191:in `dispatch'
actionpack (5.2.4.4) lib/action_controller/metal.rb:236:in `block in action'
devise (4.7.3) lib/devise/failure_app.rb:74:in `recall'
devise (4.7.3) lib/devise/failure_app.rb:41:in `respond'
actionpack (5.2.4.4) lib/abstract_controller/base.rb:194:in `process_action'
actionpack (5.2.4.4) lib/abstract_controller/base.rb:134:in `process'
actionpack (5.2.4.4) lib/action_controller/metal.rb:191:in `dispatch'
actionpack (5.2.4.4) lib/action_controller/metal.rb:236:in `block in action'
devise (4.7.3) lib/devise/failure_app.rb:23:in `call'
devise (4.7.3) lib/devise/delegator.rb:7:in `call'
warden (1.2.9) lib/warden/manager.rb:143:in `call_failure_app'
warden (1.2.9) lib/warden/manager.rb:129:in `process_unauthenticated'
warden (1.2.9) lib/warden/manager.rb:44:in `call'
rack (2.2.3) lib/rack/tempfile_reaper.rb:15:in `call'
rack (2.2.3) lib/rack/etag.rb:27:in `call'
rack (2.2.3) lib/rack/conditional_get.rb:40:in `call'
rack (2.2.3) lib/rack/head.rb:12:in `call'
actionpack (5.2.4.4) lib/action_dispatch/http/content_security_policy.rb:18:in `call'
rack (2.2.3) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.3) lib/rack/session/abstract/id.rb:260:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/cookies.rb:670:in `call'
activerecord (5.2.4.4) lib/active_record/migration.rb:559:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:98:in `run_callbacks'
actionpack (5.2.4.4) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/executor.rb:14:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
web-console (3.7.0) lib/web_console/middleware.rb:135:in `call_app'
web-console (3.7.0) lib/web_console/middleware.rb:22:in `block in call'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `catch'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
railties (5.2.4.4) lib/rails/rack/logger.rb:38:in `call_app'
railties (5.2.4.4) lib/rails/rack/logger.rb:28:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/request_id.rb:27:in `call'
rack (2.2.3) lib/rack/method_override.rb:24:in `call'
rails_same_site_cookie (0.1.8) lib/rails_same_site_cookie/middleware.rb:13:in `call'
rack (2.2.3) lib/rack/runtime.rb:22:in `call'
activesupport (5.2.4.4) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/executor.rb:14:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/static.rb:127:in `call'
rack (2.2.3) lib/rack/sendfile.rb:110:in `call'
railties (5.2.4.4) lib/rails/engine.rb:524:in `call'
puma (3.12.6) lib/puma/configuration.rb:227:in `call'
puma (3.12.6) lib/puma/server.rb:706:in `handle_request'
puma (3.12.6) lib/puma/server.rb:476:in `process_client'
puma (3.12.6) lib/puma/server.rb:334:in `block in run'
puma (3.12.6) lib/puma/thread_pool.rb:135:in `block in spawn_thread'

該当のソースコード

CSRF に関係する部分はとくに明示的に何かかいてるわけではなく
Rails がかってに埋め込んだり処理してくれてると思うんですが
原因特定に必要なソースがあれば提示します

app/views/layouts/application.html.haml には

    = csrf_meta_tags

はかかれてあります

試したこと

エラーをはいている
lib/action_controller/metal/request_forgery_protection.rb
このファイルの中をデバッグしようと考えました

まず docker コンテナ上で gem environments を叩くと

RubyGems Environment:
  - RUBYGEMS VERSION: 2.7.7
  - RUBY VERSION: 2.5.1 (2018-03-29 patchlevel 57) [x86_64-linux]
  - INSTALLATION DIRECTORY: /usr/local/bundle
  - USER INSTALLATION DIRECTORY: /root/.gem/ruby/2.5.0
  - RUBY EXECUTABLE: /usr/local/bin/ruby
  - EXECUTABLE DIRECTORY: /usr/local/bundle/bin

となっていて /usr/local/bundle 以下にあるみたいですが
コンテナ内では vi しか使えなくて不便なので
ホスト上にボリュームマウントしてる RAILS_ROOT 内にジェムをインストールしようと考え、

bundle install --path vendor/bundle/

を実行したところ正常にインストールされました

Bundle complete! 47 Gemfile dependencies, 148 gems now installed.
Bundled gems are installed into `./vendor/bundle`

ところがその後 rails s や rails db:migrate 等の rals コマンドを叩いたところ固まったまま反応しなくなってしまいました

検索してみると spring stop を実行しろという記事がたくさんでてくるのですが
Spring is not running
といわれるだけで改善しません

docker コンテナなので ./vendor/bundle にインストールする前には簡単に戻せるのですが
結局デバッグもまともにできない状態です

質問まとめとしては

1. authenticity_token がパラメータにうめこまれているにもかかわらず CSRF に失敗する理由

2. その原因を調査する方法

3. RubyGems Environment が /usr/local/bundle の状態で
   bundle install --path vendor/bundle/ を行うと rails コマンドが固まってしまう理由

の３点いずれかでいいので回答いただけるとありがたいです

補足情報（FW/ツールのバージョンなど）

ホスト：
MAC OSX
docker desktop 2.0.1.5

ゲスト：
ruby:2.5.1 コンテナイメージ
bundler 1.16.2
rails-5.2.0

よろしくお願いいたします

Answer 1

ジェム内のソースにデバッグを仕込んだところ create では CSRF は成功していて
単に認証に失敗して 401 がかえっているだけで
その後 new にリダイレクトされてるんですがそれがなぜか POST になっているようでした

リダイレクトの new アクションがなぜPOSTになったかは不明ですが
当初の質問内容とずれるのでいったん閉めます