[Rails]エラーの内容をログに出力したい ~ログレベルとloggerについて。また、例外処理との合わせ技も

はじめに - この記事の内容はどんなときに役立つか

アプリケーション上に表示されるエラー文が抽象的すぎてどうしてエラーが起きているのかわからない、しかもログを見てもエラー内容がわからない、なんてことはないでしょうか？
実装者にすぐ確認ができれば良いのですが実装者がすでにチームを去っているなんてことは度々ありますし、そもそもこういうエラーは実装者が想定していなかったりします。テストちゃんと書けよとか思ったりしますが
私が仕事上でそういう事案にぶつかった際にログに出力する方法を教えていただいて解決できたので、その方法を残しておきます

前提知識 - ログレベルについて

Rubyのログにはログレベルがあります

ログレベル(数字)	ログレベル	意味
5	unknown	常に記録されるべき不明なエラー
4	fatal	プログラムをクラッシュさせるような制御不可能なエラー
3	error	制御可能なエラー
2	warn	警告
1	info	一般的な情報
0	debug	低レベルの情報

https://docs.ruby-lang.org/ja/latest/library/logger.html

ログは設定しているログレベル以上のものが出力されます
ex) warn(2)で設定すれば、warn(2),error(3),fatal(4),unknown(5)のものがログに出力されます

ログレベルの設定方法(2023/02/05追記)

ログレベルはconfig/environments配下のファイルで、環境ごとに設定することができます。
1つ例を出しましょう

config/environments/development.rb

config.log_level = :info # 数値で表せば1

このような記述があれば、development環境のログにはログレベルはinfo(1)以上のものが出力されます。

ログレベルの設定はconfig.log_level = :ログレベルで行うことが可能です
また、デフォルトの設定はdebug(0)となっており、全てのログが出力されます

加えて、config/application.rbにconfig.log_level = :ログレベルと記述すれば、環境を問わず ログレベルが設定されます。

config/application.rb

config.log_level = :warn # 数値で表せば2

このような記述をすれば、全ての環境でログレベル2以上のものが出力されるように設定されます。

また、Rails.logger.levelを使うことでもログレベルの設定ができますが、こちらは私の理解が及んでいないため、正しく理解でき次第追記します。

ログに情報を出力する(2023/02/05追記)

ログに出力したい情報を出力するには、loggerを使います

hoge_controller.rb

def index
  logger.info("indexメソッドだよ")
  # 処理
end

このように記述すれば、hoge_controller.rbのindexメソッドを実行した際に、ログレベルinfo(1)でindexメソッドだよと出力されます。

I,[yyyy-mm-dd ~省略~ ]INFO -- :indexメソッドだよ

のような出力になります

ログレベルと出力されるログについて練習しましょ〜(2023/02/05追記)

以下の場合、development環境のログにhoge fuga piyoがそれぞれ出力されるか考えてみましょう。

config/environments/development.rb

config.log_level = :error # 数字で表すと3

hogehoge_controller.rb

def index
  logger.info("hoge")
  logger.fatal("fuga")
  logger.error("piyo")
end

解説と答え

この問題でのdevelopment環境のログはログレベルがerror(3) 以上 の情報が出力されます。
hogeはログレベルinfo(1)の情報です => 出力されません
fugaはログレベルfatal(4)の情報です => 出力されます
piyoはログレベルerror(3)の情報です => 出力されます
したがって、以下のような出力になります

F,[yyyy-mm-dd ~省略~ ]FATAL -- :fuga
E,[yyyy-mm-dd ~省略~ ]ERROR -- :piyo

本題に戻ります

ローカル環境のログレベルは大抵debug(0)に設定されている = 全ての情報がログに出力される状態になっているかと思います。
しかし、本番環境のログレベルはinfo(1)に設定されていたりします。そのためバグ調査をしようにも調べようがない。。。なんてことも起き得ます

そんなわけで、エラー内容を強制的に出力させましょう

ログレベルの設定がinfo(1)のアプリケーションで、新しい情報を登録する処理中によくわからないエラーが起きたと想定しましょう
アプリケーション上でもログでもわからないのでソースコードを見にいきます

def create
  # 処理
rescue
  flash.now[:alert] = '不正だよ'
  render(:new)
end

例外処理が行われていることしかわかりません。まあ場合によってはバリデーションエラーかな？みたいな推測は立ちますが、推測の域を出ないかと思います。
こんなフラッシュ出されても意味ねえだろと殺意を覚える方もいらっしゃるかもしれませんが、まあそこはユーザーに見せられないのかもしれないと許しましょう。

はい、そんなわけで(?)ログにエラー内容を出力されます

def create
  # 処理
rescue => e
  logger.error(e.message) # ログレベル3で出力する
  flash.now[:alert] = '不正だよ'
  render(:new)
end

このように記述することで、ログレベルerror(3)でエラー内容を出すことができます
このアプリケーションのログレベルはinfo(1)に設定されていますので、無事にエラー内容がログに出力されることになります

E,[yyyy-mm-dd ~省略~ ]ERROR -- :Userを入力してください。

このようなログが出力されれば、Userの入力に問題があることがわかりますね

仕組み

rescue => e

この行でエラー内容をeに格納します

logger.error(e.message)

続いて、こちらの行でeに格納されたエラー内容をログに出力します
分解していきましょう
logger.ログレベル（hoge)で指定のログレベルでhogeを出力します
e.messageはeに格納されているエラーメッセージです
つまり、この行での処理は
ログレベルerror(3)でエラーメッセージを出力してね
ということになります

まとめ

ログに関する基本的な知識と、例外処理に関する基本的な知識の合わせ技ですが、まあ使える場面はままあるかなと。
e.messageをアプリケーション上に出力することの方が多い気がせんこともないですが。。。
私は今回紹介した方法でエラー内容がわかり修正パッチのリリースができたので、私みたいな状況に陥ったよわよわエンジニア(私のなかーま！）が助かったらいいな〜ぐらいの気持ちで残しておきます。

参考文献

• https://docs.ruby-lang.org/ja/latest/library/logger.html
• https://qiita.com/sobameshi0901/items/b963e7046e2ae8b8e813
• https://qiita.com/ngron/items/4c319ae7340b72c7e566
• https://railsguides.jp/debugging_rails_applications.html#ロガー
• https://qiita.com/Kashiwara/items/f8a4030da6b17e96fabf