Rake タスクの Unhandled Exception を Rails.logger でログ出力する方法

はじめに

こんにちは、Plex Job開発チームの種井です。

これまで、Railsアプリケーションから構造化ログを出力する上でいくつか試行錯誤を行ってきました。 今回は、その中で行った「Rakeタスクで発生した例外をRails.loggerとしてログ出力する」取り組みについて紹介したいと思います。

構造化ログに関連する取り組みについては、よければ過去の記事もご覧ください。

• Railsアプリケーションのログを構造化してDatadogで活用するまで
• Semantic LoggerのログをDatadog用にカスタマイズしてみた
• ActiveJobのloggerメソッドをスタブするはなし

課題

Plex Job開発チームでは、構造化ログの出力にSemantic Loggerを活用しています。 Railsアプリケーションで利用する場合は、rails_semantic_logger gemを導入することにより、Rails.loggerが拡張されます。これにより基本的なRailsアプリケーションからのログ出力は自動的に構造化されます。

導入時は気づきませんでしたが、運用をはじめてからRakeタスクで発生した例外のみ構造化されないままログ出力されていることに気づきました。

以下は出力の例

bin/rails aborted!

/workspaces/sample/lib/tasks/hoge.rake:3:in 'block (2 levels) in <main>'
Tasks: TOP => hoge:fuga
(See full trace by running task with --trace)

というのも、Rakeタスクで発生した例外はtaskブロック内で捕捉しない限り、Rakeのログ出力機能によってエラー出力されてしまいます。

以下は、rakeの該当箇所のコードになります。

...

# Provide standard exception handling for the given block.
def standard_exception_handling # :nodoc:
  yield
rescue SystemExit
  # Exit silently with current status
  raise
rescue OptionParser::InvalidOption => ex
  $stderr.puts ex.message
  exit(false)
rescue Exception => ex
  # Exit with error message
  display_error_message(ex)
  exit_because_of_exception(ex)
end

...

# Display the error message that caused the exception.
def display_error_message(ex) # :nodoc:
  trace "#{name} aborted!"
  display_exception_details(ex)
  trace "Tasks: #{ex.chain}" if has_chain?(ex)
  trace "(See full trace by running task with --trace)" unless
      options.backtrace
end

RakeタスクはRailsコマンドで実行することが可能ですが、タスクの実行についてはRailsのエコシステムで実行されるわけではありません。例外についても独自の機能traceメソッドでエラー出力されます。

Plex JobではRakeタスクで定期バッチを実装しています。

その他のログと同様に監視ツールからモニタリングしたいので、Rails.loggerを経由してUnhandled Exceptionをfatalやerrorレベルの構造化ログとして出力する必要がありました。

Rakeの挙動

そのため、RakeタスクからRails.loggerを経由してログを出力する方法を検討してみることにしました。

実現方法の検討

調査・検討してみたところ、いくつか方法がありました。

1. begin ... rescue ... end で処理を囲う
2. Rake にパッチをあてる
3. at_exit を使用する

それぞれの方法について見ていきたいと思います。

1. begin ... rescue ... end で処理を囲う

• task ブロックの処理をすべて begin ...rescue ... end で囲う
• 例外が発生した場合は、Rails.logger でログを出力する

以下は実装例です。

namespace :hoge do
  desc "実装例"
  task fuga: :environment do
    begin
      # do something
    rescue => e
      Rails.logger.fatal(e)
      raise e
    end
  end
end

• メリット
  • シンプルで理解しやすい
• デメリット
  • 毎回書くのが面倒
  • 実装漏れが発生する可能性が高い

2. Rake にパッチをあてる

• Rake にモンキーパッチをあてる
• Rake タスク実行時にかならず例外をキャッチし、Rails.loggerでログを出力する

以下は実装例です。

module Rake
  class Task
    alias_method :invoke_without_loggable, :invoke

    def invoke(*args)
      begin
        invoke_without_loggable(*args)
      rescue StandardError => e
        Rails.logger.fatal(e)
        raise e
      end
    end
  end
end

• メリット
  • タスクの実装時にunhandled errorのハンドリングを意識する必要がない
• デメリット
  • Rake の内部実装が変わると壊れる可能性がある

参考

• https://stackoverflow.com/questions/62501459/rails-how-to-log-all-exceptions-thrown-in-rake-tasks
• https://blog.naoty.dev/274/

3. at_exit を使う

• at_exit ブロックを定義して、ランタイムの終了時に呼び出される処理を登録する
• sentry をはじめとした監視ツールの SDK もエラートラッキングのために at_exit を使用して例外を捕捉してログを収集していたりする
  • https://github.com/getsentry/sentry-ruby/blob/v2.12.3/lib/raven/instance.rb#L219-L227
  • https://docs.honeybadger.io/lib/ruby/integration-guides/rails-exception-tracking/

以下は実装例です。

namespace :db do
  desc "This task does nothing"
  task nothing: :environment do
    at_exit do
      exception = $ERROR_INFO
      Rails.logger.fatal(exception)
    end
    ...
  end
end

• メリット
  • 導入が簡単
  • タスクの実装時にunhandled errorのハンドリングを意識する必要がない
• デメリット
  • 副作用に注意する必要がある(前後関係で処理が上書きされたり、したりしてしまう)

参考

• https://docs.ruby-lang.org/ja/latest/doc/spec=2fterminate.html
• https://speakerdeck.com/bgpat/at-exit?slide=14

どの方法で実装するか？

begin ... rescue ... end で処理を囲う方法は、完全に実装漏れを防ぎきることが難しい。

at_exitを使う方法については、

• 登録した処理の実行順番を意識する必要がある
• よく使うgemにも組み込まれていることが多い

こともあり、アプリケーションコードに組み込む上で、副作用を考慮しながら保守し続けるのはコストが高くつきそうでした。

今回は保守性を考慮して、Rake にパッチをあてる方法が落とし所としてはよさそうだという判断となりました。

観点としては以下となります。

• 例外時のログ出力について、実装の漏れが発生しない
• パッチをあてる対象が限定的で、将来Rakeのインターフェースが多少変更されても修正が容易であること
• 処理がRakeだけに依存していること(その他のgemやアプリケーションコードへの影響を考慮する必要がない)

Rakeにパッチをあてる

方針が決まったので、実際にRakeにパッチをあてることにします。

https://github.com/ruby/rake/blob/79bf96f9aa3219ce87a4979e78fb206a29d18dac/lib/rake/application.rb#L235を参考にdisplay_error_messageメソッドにモンキーパッチを当てることで実装を行いました。

以下は実装例です。

Rakefile

# Add your own tasks in files placed in lib/tasks ending in .rake,
# for example lib/tasks/capistrano.rake, and they will automatically be available to Rake.

require_relative "config/application"

# RakeExtensionモジュールを作成して、パッチ処理を実装する
module RakeExtension
  def display_error_message(ex)
    # Semantic Loggerでログ出力する
    logs_error_for_semantic_logger(ex)

    super(ex)
  end

  def logs_error_for_semantic_logger(ex)
    task_name = ex.chain if has_chain?(ex)
    Rails.logger.fatal("#{name} aborted! Tasks: #{task_name}", ex)
  end
end

Rails.application.load_tasks

# Railsの初期化後にRake::Applicationを拡張する
Rake::Application.prepend(RakeExtension)

上記のようなパッチをあてることで、以下のようにtaskブロックで発生した例外がRails.logger(Semantic Loggger)により構造化されてログが出力されるようになりました。

以下は出力の例

{"host":"004c21fd7993","application":"Semantic Logger","timestamp":"2025-07-24T06:23:03.354088Z","level":"fatal","level_index":5,"pid":6481,"thread":"1816","file":"/workspaces/sample/rakefile","line":17,"name":"Rails","message":"bin/rails aborted! Tasks: TOP =\u003e hoge:fuga","exception":{"name":"RuntimeError","message":"","stack_trace":["/workspaces/sample/lib/tasks/hoge.rake:3:in 'block (2 levels) in ..."]}}

おわりに

弊社では各事業部でエンジニアを募集しております！ 気になるポジションあればお気軽にお問い合わせください。一緒に働きましょう。

弊社の各事業部でエンジニアを求めています！

SaaS

100兆円規模のインフラ産業の課題解決に挑戦｜業務支援SaaSのテックリード - 株式会社プレックス

急成長する業務支援SaaSのソフトウェアエンジニア・リードエンジニア - 株式会社プレックス

PLEX JOB

インフラ産業の人材課題を解決 | フロントエンドの技術を牽引するテックリード - 株式会社プレックス

インフラ領域で日本を動かす仕組みを作るスタートアップのエンジニア - 株式会社プレックス

コーポレート

オペレーションの効率化によって事業成長に貢献するコーポレートエンジニア - 株式会社プレックス

参考

• https://docs.ruby-lang.org/ja/latest/method/Module/i/prepend.html
• https://github.com/ruby/rake/blob/79bf96f9aa3219ce87a4979e78fb206a29d18dac/lib/rake/application.rb#L235
• https://techracho.bpsinc.jp/hachi8833/2018_04_12/54738