RailsのConfigの読み込み順を知っていますか…？initializersに設定した内容が反映されなかった話

:::note info
この記事は [クラウドワークス グループ Advent Calendar 2024](https://qiita.com/advent-calendar/2024/crowdworks) シリーズ1の11日目の記事です。
:::

こんにちは。クラウドワークスで不正利用対策チームのバックエンドエンジニアとして働いている得能 ([@yoshi_10_11](https://x.com/yoshi_10_11)) です。

今回はinitializersに設定した内容が反映されなかった話です。

Railsのconfig内で`application.rb`、`environments/xxx.rb`、`initializers/xxx.rb`などのファイルを編集することがあるかと思います。みなさんはこれらがどのように読み込まれるのかを知っていますか？

完全解説！とまではいきませんが、最終的には`initializers/xxx.rb`のファイルを読み込むコードを読むところまで書いていきますのでひとつの参考になればと思います。

# 事例

`config/application.rb`に以下のLogger設定コードが記述されていました。

※記事用にコードを簡略化しています
```ruby
# config/application.rb
logger = ActiveSupport::Logger.new(STDOUT)
logger.formatter = JsonLogFormatter.new
config.logger = ActiveSupport::TaggedLogging.new(logger)
``` 

`JsonLogFormatter`はLoggerをJSONで出力するための設定です。(RailsのデフォルトはJSON出力ではない)
JSON化したログ出力は出力先で捕捉して保存しAamazon Athenaで閲覧できるようになっています。

`config/application.rb`内はLogger設定以外にもいろいろ設定コードが記載されているため情報量が多い状態でした。

そこで、「Loggerの設定を`initializers`に切り出して可読性を上げよう！」と考えました。
`config/initializers/logger.rb`という新規ファイルを作成し、上記のコードをそのまま移動させました。

ファイル分割を行ったことでLogger設定がどこで行われているのかがわかりやすくなりました。

しかし、コードの変更前後でログの出力に差異がないかをリリース前にStaging環境でテストしてみたところ、Logger設定が反映されなくなった(RailsのデフォルトのLogger設定が反映されている状態)ことがわかりました。

**Loggerの定義場所を移動しただけでLoggerの設定が変わってしまった**のです。

JsonLogFormatterなどのFormatter設定が無効になり、非JSON形式となったログを捕捉することができなくなり、適切に保存されなくなってしまいました…
![logger.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/135860/a69d5128-5a1d-2305-b13b-505758f2309c.png)


# 仮説

なぜこのような問題が起きたのでしょう？

Loggerの設定コードの記述自体は変更しておらず、定義する場所が変わったのみです。コード自体に問題があればRailsアプリケーション起動時に何かしらのエラーが起きると思われるため、コード自体には問題はないと思いました。

Logger設定は`config/application.rb`以外にも`config/environments`配下などでも設定することがあり、そちらの場合は問題なく動作します。

そのため、Railsアプリケーション起動時のRailsのConfig周辺の読み込み順の問題なのではないか。`config/initializers`の読み込み順は全体の中でも遅めの部類に入るのではないか。という仮説を立てました。

# RailsのConfigの読み込み順を調査する

では実際に調査をしてみましょう。

## Railsガイドを読んでみる

まずはRailsガイドを読んでみましょう。

[Rails の初期化プロセス](https://railsguides.jp/initialization.html)

まずは「1. 起動!」の章を読んでみましょう。
細かい説明はRailsガイドを読んでいただければわかるので省略しますが、開発するRailsアプリケーション内で定義するファイルについてのみ触れると、
Railsが起動後に`config/application`、`config/environments`の順に読み込まれます。

`config/environments`内に記述したLogger設定は有効に機能するので、ここまでの設定はまだ問題ありません。

さらに読み進めて「2. Railsを読み込む」を見てみましょう。
「2.3 railties/lib/rails/application.rb」を見ると

```ruby
def initialize!(group = :default) # :nodoc:
    raise "Application has been already initialized." if @initialized
    run_initializers(group, self)
    @initialized = true
    self
end
```
>アプリケーションは一度だけ初期化できます。railties/lib/rails/initializable.rbで定義されているrun_initializersメソッドによって、Railtieのさまざまなイニシャライザが実行されます。

引用元: https://railsguides.jp/initialization.html#railties-lib-rails-application-rb

と書かれています。

こちらに書かれている`initializers`は
>Railtieイニシャライザ全体と、load_config_initializersイニシャライザのインスタンスやそれに関連するconfig/initializers以下のイニシャライザ設定ファイルを混同しないようにしましょう。

引用元: https://railsguides.jp/initialization.html#railties-lib-rails-application-rb

と書かれているようにイコール`config/initializers`ではないため注意が必要です。Railsアプリケーションを実行するうえで初期化処理を行うものを処理する箇所になります。

しかし、`config/initializers`とはイコールではありませんが、この初期化処理されるリストの中に`config/initializers`で定義したファイル群が含まれます。そのため、この中の`run_initializers`を見ると今回の疑問を解消することができそうです。

`railties/lib/rails/initializable.rb`
```ruby
def run_initializers(group = :default, *args)
    return if instance_variable_defined?(:@ran)
    initializers.tsort_each do |initializer|
        initializer.run(*args) if initializer.belongs_to?(group)
    end
    @ran = true
end
```
引用元: https://railsguides.jp/initialization.html#railties-lib-rails-application-rb

読んでみるとざっくり`initializers`を`tsort_each`して、ひとつひとつ`run`で初期化処理をしているという流れに見えます。

`tsort_each`はトポロジカルソートしてイテレータを返すメソッドで、各initializerの処理の順序依存を考慮したソートをしてくれます。

[Ruby tsort_each](https://docs.ruby-lang.org/ja/latest/method/TSort/i/tsort_each.html)

## より詳細に実装を追ってみる

initializersに実際にどんな物が入っているのかを見てみたいですね。ちょっと簡単に見てみましょう。

`railties/lib/rails/initializable.rb`で`run_initializers`内にデバッガーを埋め込んでRailsサーバーを起動してみましょう。環境依存などがないように新規で`rails new`で作成したアプリケーションを確認すると良いかもしれません。

デバッガーでinitializersの中身を見てみると
```shell
#<Rails::Initializable::Initializer:0x000000012dd84dd8
 @after=nil,
 @before=nil,
 @block=#<Proc:0x000000014a4d78f8 /Users/user/repos/rails/railties/lib/rails/application/bootstrap.rb:13>,
 @context=#<MytestApp::Application>,
 @group=:all,
 @name=:load_environment_hook>
```
のようなデータをたくさん持ったものであることがわかりました。これらすべてRails起動時の初期化処理対象です。
ちなみに、`Rails::Initializable::Initializer`を読み込むと`tsort_each_child`でtsortで並び替える基準の設定を行っているのもわかります。

件数もとても多いですね。
```ruby
initializers.count
# => 344
```

で、この中の`@name`を頼りに調べてみると、

`:load_config_initializers`(定義場所: railties/lib/rails/engine.rb)
`:initialize_logger`(定義場所: railties/lib/rails/application/bootstrap.rb)

が見つかりました。(`load_config_initializers`は複数見つかりますが、詳細をよく見ると`@context`の中身が違っていたりします。こちらの説明は割愛。)

それぞれを詳しく見てみます。

`:load_config_initializers`は`config/initializers`配下の読み込み処理を行っていますね。

```ruby
initializer :load_config_initializers do
    config.paths["config/initializers"].existent.sort.each do |initializer|
        load_config_initializer(initializer)
    end
end
```
引用元: [rails/railties/lib/rails/engine.rb](https://github.com/rails/rails/blob/410ad1c8a18ebf7f544d77d2cb82de2a0e87d23a/railties/lib/rails/engine.rb#L644-L648)

`:initialize_logger`の処理内容は既に設定した`config.logger`があればそちらを、なければloggerのデフォルト設定を`Rails.logger`に代入しているようです。

```ruby
Rails.logger ||= config.logger || begin
  logger = if config.log_file_size
    ActiveSupport::Logger.new(config.default_log_file, 1, config.log_file_size)
  else
    ActiveSupport::Logger.new(config.default_log_file)
  end
  logger.formatter = config.log_formatter
  logger = ActiveSupport::TaggedLogging.new(logger)
  logger
```

引用元: [rails/railties/lib/rails/application/bootstrap.rb](https://github.com/rails/rails/blob/410ad1c8a18ebf7f544d77d2cb82de2a0e87d23a/railties/lib/rails/application/bootstrap.rb#L35-L43)

Rails.loggerに代入された設定がRailsアプリケーションに最終的に反映されるLogger設定となるため、固有のLogger設定を行いたい場合は`:initialize_logger`が実行される前に設定する必要性がありそうです。

上記の初期化処理の読み込み順を見てみます。
`run_initializers`内の `initializers.tsort_each` で読み込み順の決定、周回を行っているため、各initializerのnameを出力する方法で確認してみます。

```ruby
# 処理順にinitializerの名前を出力
initializers.tsort_each { |initializer| p initializer.name }
=> 
...
:initialize_logger
...
...
...
:load_config_initializers
...
```

はい、先に`:initialize_logger`が読み込まれていますね。つまり、initializers配下に定義したLogger設定が反映されなかったのは、**`:load_config_initializers`が`:initialize_logger`より後に呼ばれるから**だったというわけです。

# 他に気をつけるべき定義はないかな？

では、Logger以外に`config/initializers`に定義しても反映されないもの、気をつけるべきものはあるのでしょうか？その他のinitializerの読み込みを見てみると…

```ruby
# 処理順にinitializerの名前を出力
initializers.tsort_each { |initializer| p initializer.name }
=> 
...
:initialize_cache,
...
"action_xxx.set_configs",
 ...
"action_xxx.set_configs",
...
...
...
:load_config_initializers
...
```

人によって気になるものはいろいろあるかと思いますが、CacheやActionXXXの設定(XXXにはMailerやControllerなどが入ります)は`config/initializers`が呼ばれる前に確定するようです。

基本的にこれらは`config/environments`配下で定義していることが多いと思うのでそこまで気にする必要はないかもしれませんが、もし、「設定定義をわかりやすくファイル分割したいんや！」と思った際には、initializerの読み込み順について思い出してみてください。

# おわりに

Logger設定を`config/initializers`に移動しただけで設定が反映されなくなった！？という事例からinitializersの読み込みタイミングを実装コードで見るところまでご紹介しました。このあたりご存知でしたか？

Railsアプリケーションを新規開発時にはそこまで気にならないかもしれませんが、プロダクトが大きくなるとともにファイル分割したい、凝った設定を組み込みたいという要望が高まるので、もしかすると今回と同じような場面に遭遇することがあるかもしれません。

なんとなく`config/initializers`に入れておいたものはすべてRailsアプリケーション起動前に実行してくれる！と思いがち(私だけ？)ですが、決してそうではないことがわかりました。
なにかの設定を追加する際には今回の読み込み順を意識して設定するとよいでしょう。また、興味があれば、その他の設定についてもどのような順番で読み込まれているのかを確認しておくとおもしろいかもしれません。