本番環境でRails.application.secrets.secret_key_baseが原因で本番環境でjwtを使うことができなかったのでメモを残します。
エラーの原因調査
エラーのログ
heroku logs -tail
2021-10-25T12:59:16.093104+00:00 heroku[router]: at=info method=OPTIONS path="/v1/accounts" host=api-slack-react-ruby.herokuapp.com request_id=b010205a-d1b1-4436-aa04-ad84e944e2ea fwd="153.246.218.124" dyno=web.1 connect=0ms service=1ms status=200 bytes=287 protocol=https
2021-10-25T12:59:16.273962+00:00 heroku[router]: at=info method=GET path="/v1/accounts" host=api-slack-react-ruby.herokuapp.com request_id=0e2bccc5-9a32-4ccf-9689-e8e375ea8556 fwd="153.246.218.124" dyno=web.1 connect=0ms service=3ms status=500 bytes=374 protocol=https
2021-10-25T12:59:16.271652+00:00 app[web.1]: I, [2021-10-25T12:59:16.271587 #4] INFO -- : [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] Started GET "/v1/accounts" for 153.246.218.124 at 2021-10-25 12:59:16 +0000
2021-10-25T12:59:16.272513+00:00 app[web.1]: I, [2021-10-25T12:59:16.272471 #4] INFO -- : [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] Processing by V1::AccountsController#callback as HTML
2021-10-25T12:59:16.273001+00:00 app[web.1]: I, [2021-10-25T12:59:16.272917 #4] INFO -- : [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] Completed 500 Internal Server Error in 0ms (ActiveRecord: 0.0ms | Allocations: 130)
2021-10-25T12:59:16.273322+00:00 app[web.1]: F, [2021-10-25T12:59:16.273291 #4] FATAL -- : [0e2bccc5-9a32-4ccf-9689-e8e375ea8556]
2021-10-25T12:59:16.273322+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] JWT::DecodeError (No verification key available):
2021-10-25T12:59:16.273323+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556]
2021-10-25T12:59:16.273323+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] lib/j_w_t/helper.rb:12:in `decode'
2021-10-25T12:59:16.273324+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] app/models/concerns/j_w_t/authenticatable.rb:23:in `authenticate!'
2021-10-25T12:59:16.273325+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] app/controllers/concerns/authenticatable.rb:15:in `authenticate_account!'
でみてみると
2021-10-25T12:59:16.273322+00:00 app[web.1]: [0e2bccc5-9a32-4ccf-9689-e8e375ea8556] JWT::DecodeError (No verification key available):
ここらへんが原因だと思う
該当するコードが以下
def decode(token, verify: true, **opts)
JWT.decode(token, Rails.application.secrets.secret_key_base, verify, **opts)
end
原因としてはRails.application.secrets.secret_key_baseが怪しいと思ったので、調査してみると。。。
heroku run bash
rails c
Rails.application.secrets.secret_key_base
すこし原因調査が長くなってしまったが、ここから解決していこうと思う
試した方法
-
rails consoleでRails.application.secrets.secret_key_baseの値を取得後に、heorkuの環境変数にSECRET_KEY_BASEをセット
↓
変わらず。。。 -
herokuの環境変数にRAILS_MASTER_KEYをセット
heroku config:set RAILS_MASTER_KEY=cat config/master.key
↓
変わらず。。。
- Rails.application.secret.secret_key_baseをRails.application.credentials.secret_key_baseに変更した
def decode(token, verify: true, **opts)
JWT.decode(token, Rails.application.secrets.secret_key_base, verify, **opts)
end
def decode(token, verify: true, **opts)
JWT.decode(token, Rails.application.credentials.secret_key_base, verify, **opts)
end
↓
うまく行った!!!
結論
herokuの環境変数にRAILS_MASTER_KEYをセットし、Rails.application.secret.secret_key_baseをRails.application.credentials.secret_key_baseに変更するとうまく行った!
うまく行った理由を調べてみると、Railsは5.1から秘匿情報をsecret.ymlではなく、credentials.yml.encで管理するようになったらしい。
そのため、secret_key_baseの参照先もsecretsからcredentialsに変わったということだろう。
また、秘匿情報を見るためにはmaster keyを環境変数にセットする必要があるので2.で試したことも有効だったと考えられる。
かなり時間を使ってしまったが、解決することができてよかった。