Rails6 のちょい足しな新機能を試す 120（Rails.logger in Fiber編)

はじめに

Rails 6 に追加された新機能を試す第120段。 今回は、Rails.logger in Fiber 編です。
Rails 6 (と Rails 5.2.4.1) では、Fiber の中で Rails.logger.local_level でログレベルを変更しても、それが親(Fiber の親)に影響を与えないようになっています。

Ruby 2.6.5, Rails 6.0.2.1, Rails 5.2.4.1, Rails 5.2.3 で確認しました。 (Rails 6.0.0 でこの修正が入っています。)

$ rails --version
Rails 6.0.2.1

今回は、適切な利用例を思いつきませんでした。controller を1つ作って、 index の中で、 Fiber を使って確認します。

Rails プロジェクトを作る

Rails プロジェクトを新たに作成します。

$ rails new rails_sandbox
$ cd rails_sandbox

Home コントローラを作る

index ビューを持つ Home コントローラを作成する。

$ bin/rails g controller Home index

Controller を修正する

Controller を修正し、 index の中で、Fiber を使います。 Fiber#resume を呼ぶ前後で、Rails.logger

app/controllers/home_controller.rb

class HomeController < ApplicationController
  def index
    Rails.logger.level = 1
    Rails.logger.info("[Before] Rails.logger.debug? #{Rails.logger.debug?}")

    Fiber.new do
      Rails.logger.local_level = 0
      Rails.logger.info("[Fiber] Rails.logger.debug? #{Rails.logger.debug?}")
    end.resume

    Rails.logger.info("[After] Rails.logger.debug? #{Rails.logger.debug?}")
  end
end

rails server を実行して確認する

rails server を実行し、 http://localhost:3000/home/index にアクセスすると以下のように出力されます。

[Before] Rails.logger.debug? false
[Fiber] Rails.logger.debug? true
[After] Rails.logger.debug? false

Rails 5 では

5.2.4 では、Rails 6 と同様の動作をしますが、 Rails 5.2.3 では、以下のように Fiber#resume 実行後、元に戻りません。

[Before] Rails.logger.debug? false
[Fiber] Rails.logger.debug? true
[After] Rails.logger.debug? true

その他

どうもよくわからない事象が1つ。
以下のように、 Fiber.new のブロックの中を Rails.logger.info から Rails.logger.debug に修正します。

/app/

...
    Fiber.new do
      Rails.logger.local_level = 0
      Rails.logger.debug("[Fiber] Rails.logger.debug? #{Rails.logger.debug?}")
    end.resume
...

そうするとなぜか以下のようにFiberの中のログ出力が無視されてしまいました。

Rails.logger.debug? が true になるので、 Rails.logger.debug でも出力されるかと思ったのですが...

[Before] Rails.logger.debug? false
[After] Rails.logger.debug? false

試したソース

参考情報

• Make ActiveSupport::Logger Fiber-safe