デバッグログのブロック化によるメッセージ生成コストの最適化
デバッグが無効な環境でも文字列補間が実行される問題を解消するため、Puma::LogWriter#debug がブロック引数に対応しました。これにより、デバッグモードが無効の場合はメッセージ文字列の生成自体をスキップできます。
背景
デバッグログ呼び出しが引数として渡されていたことで、デバッグが無効な場合でも文字列補間のコストが発生していました。たとえば以下のコードでは、@debug が false であっても "Drained #{drain} additional connections." の文字列補間が評価されます。
@log_writer.debug "Drained #{drain} additional connections."
この問題はRubyの評価順序に起因します。メソッド引数は呼び出し前にすべて評価されるため、ログ出力の要否にかかわらず文字列オブジェクトが生成されます。本PRはこの無駄なアロケーションをブロックで遅延評価することで排除しています。なお、同様のブロック渡しのパターンはRuby標準の Logger や Rails でも採用されている実績ある手法です。
技術的な変更
LogWriter#debug メソッドがブロック引数をサポートするよう拡張され、呼び出し側では文字列リテラルをブロックで包む形式に統一されました。
lib/puma/log_writer.rb の debug メソッドは、str を省略可能にしたうえでブロックの有無を block_given? で分岐するように変更されています。
変更前:
def debug(str)
log("% #{str}") if @debug
end
変更後:
def debug(str=nil, &block)
if @debug
if block_given?
log("% #{yield}")
else
log("% #{str}")
end
end
end
@debug が false の場合はブロックが一切 yield されないため、文字列補間を含むブロック本体の評価は行われません。文字列を引数として渡す従来の呼び出し形式も引き続き動作するため、後方互換性は維持されています。
呼び出し側の変更は binder.rb・configuration.rb・server.rb の計4箇所で、いずれも文字列引数をブロックに置き換える一行変更です。
# 変更前
@log_writer.debug "Drained #{drain} additional connections." if drain
# 変更後
@log_writer.debug { "Drained #{drain} additional connections." } if drain
テストは test/test_log_writer.rb に1件追加されており、PUMA_DEBUG=1 の環境下でブロック形式の呼び出しが正しく出力されることを検証しています。
設計判断
既存のメソッドシグネチャを拡張する方式が採用され、str=nil をデフォルト引数にすることで引数渡しとブロック渡しの両方を単一メソッドで受け付けられるようにしています。
PR本文では LogWriter#log など他のログメソッドへのブロック対応の可能性にも言及していますが、これらはログ深刻度レベルに紐付いていないとして本PRの対象外としています。また、rescue ブロック内のデバッグ呼び出しも「クリティカルパスではない」として今回は対象外とされており、変更範囲が意図的に絞られています。
ブロックを使った遅延評価の適用先をデバッグログに限定したことで、変更の影響範囲を最小化しながら最もコスト削減効果が期待できる箇所に対処しています。
まとめ
本PRはRubyにおけるログ最適化の定石パターンをPumaのデバッグログに適用したものです。debug メソッドがブロックに対応したことで、本番環境などデバッグが無効な状況での不要な文字列アロケーションが排除され、引数形式との後方互換性も維持されています。