RailsのRakeタスクでログ出力を共通化する方法をメモしておく。 Rakeタスクの賢いロギングを参考に改良してみる。
要件
- Rakeタスクの開始と終了がわかるようにログを出力する
- Rakeタスクが途中でエラーとなったら、終了ログは出力せずに、FATALログを出力する
- ログ出力をするRakeタスクが簡単に実装できるようにする
- Rails.loggerがない場合には標準出力をする
実装
Rakeタスクのログ出力Module
module TaskLogging def task(*args, &block) Rake::Task.define_task(*args) do |task, options| next unless block logger = ActiveSupport::TaggedLogging.new(Rails.logger || Logger.new(STDOUT)) logger.tagged(task.to_s) do logger.info "[#{Time.current}] Start" yield task, options logger.info "[#{Time.current}] End" rescue StandardError => e logger.fatal "[#{Time.current}] Failed: #{e.message}\n#{e.backtrace.join("\n")}" raise end end end end extend TaskLogging
テストコード
require 'rails_helper' RSpec.describe TaskLogging do include ActiveSupport::Testing::TimeHelpers describe '.task' do let(:logger_double) { instance_double('Logger', info: true, fatal: true, formatter: ActiveSupport::Logger::SimpleFormatter.new) } let(:task_logging_instance) { Class.new { include TaskLogging }.new } before do allow(Rails).to receive(:logger).and_return(logger_double) allow(logger_double).to receive(:formatter=) travel_to(Time.zone.parse('2025-12-05 10:00:00')) end context '正常系: 開始と終了ログが出力される' do it 'Start/End を順序通りに info する' do task_logging_instance.task(:test_logging_task) do |_task, _opts| # no-op end rake_task = Rake::Task['test_logging_task'] expect(logger_double).to receive(:info).with(a_string_including('[2025-12-05 10:00:00 +0900] Start')).ordered expect(logger_double).to receive(:info).with(a_string_including('[2025-12-05 10:00:00 +0900] End')).ordered rake_task.execute end end context '異常系: 例外時に FATAL ログを出して再送出する' do it 'fatal を呼んで例外を再送出する' do task_logging_instance.task(:failing_task) do |_task, _opts| raise StandardError, 'boom' end rake_task = Rake::Task['failing_task'] expect(logger_double).to receive(:info).with(a_string_including('[2025-12-05 10:00:00 +0900] Start')).ordered expect(logger_double).to receive(:fatal).with(a_string_including('[2025-12-05 10:00:00 +0900] Failed: boom')).ordered expect { rake_task.execute }.to raise_error(StandardError, 'boom') end end context 'ロガーが存在しない場合' do before do allow(Rails).to receive(:logger).and_return(nil) # NOTE: 標準出力への出力を抑制 allow($stdout).to receive(:write) end it '正常系はログが出ずに通る' do task_logging_instance.task(:no_logger_task) { |_task, _opts| } rake_task = Rake::Task['no_logger_task'] # 何も出力されない rake_task.execute end it '異常系はログなしで例外再送出される' do task_logging_instance.task(:no_logger_fail_task) { |_task, _opts| raise StandardError, 'err' } rake_task = Rake::Task['no_logger_fail_task'] expect { rake_task.execute }.to raise_error(StandardError, 'err') end end context 'ブロック未指定の場合' do it 'タスク実行してもログ出力されない' do task_logging_instance.task(:no_block_task) rake_task = Rake::Task['no_block_task'] expect(logger_double).not_to receive(:info) expect(logger_double).not_to receive(:fatal) rake_task.execute end end context '引数付きタスクでもログに引数は含まれない' do it 'Start/End ログに引数が表示されない' do task_logging_instance.task(:arg_task, [:x, :y]) do |_task, _opts| # no-op end rake_task = Rake::Task['arg_task'] expect(logger_double).to receive(:info).with(a_string_including('[2025-12-05 10:00:00 +0900] Start')).ordered expect(logger_double).to receive(:info).with(a_string_including('[2025-12-05 10:00:00 +0900] End')).ordered rake_task.invoke('foo', 'bar') end end end end
ログ出力を利用するRakeタスクは、require 'task_logging' をするだけ。
require 'task_logging' namespace :foo do task :bar => :environment do ... end end
以下のようなログが出力される
I, [2025-12-08T23:00:20.741769 #8385] INFO -- : [foo:bar] [2025-12-08 14:00:20 UTC] Start I, [2025-12-08T23:00:25.200269 #8385] INFO -- : [foo:ba] [2025-12-08 14:00:25 UTC] End
