エラー箇所を簡単に特定できるログのスマートな(?)出力方法

C言語には #define というキーワードがある。

#define ONE  1
#define TWO 2

Rubyで言えば定数の定義を行っているのに似ているが、Rubyはあくまでも頭文字が大文字で示される定数のオブジェクトに値を代入しているのにたいし、C言語ではコンパイラ処理の前にプリプロセッサというツールが「#define」の後に続く２つの文字列に対し、左側の文字列を右側の文字列にソースコード上で変換するという違いがある。

(プリプロセッサによる返還後)

#define ONE 1
....
....
a = ONE;

(プリプロセッサによる返還後)

....
....
a = 1;

見ての通り、ONEが1に置き換えられてしまう。
このようなプリプロセッサを使った文字の置き換えはC言語では一般にマクロと呼ばれ、同様の機能はRubyに存在しない。

このマクロを推し進めた特殊マクロというものがC言語にはいくつかあるのだが、その中でもRubyと同じく __FILE__ と __LINE__ というキーワードはデバッグに大変役に立つ。これらのマクロをソースコード中に埋め込むと、プリプロセッサがそのマクロの書かれたファイル名と書かれている位置（行番号）に変換してくれるからだ。

(ファイル名: abc.c)
printf("THIS IS A TEST %s line %d",  __FILE__, __LINE__);

上記のコードが実行されるとコンソールには
「THIS IS A TEST abc.c line 24」
という感じの出力が行われる。
このようにしてソースコード中にログを埋め込んでおけば、どのファイルの何行目まで処理が進んだのかを知るのに大変便利だ。

さらに推し進めると、以下のようなマクロを書くことになる。

#define log( msg ) printf("%s,%d:%s", msg, __FILE__,__LINE__)

このマクロをソースコード中に埋め込み、例えば「log("ERROR");」と書いて埋め込んでおくとその該当箇所全てが、プリプロセッサによりコンパイルの直前に「printf("%s %s %d", "ERROR", __FILE__, LINE__);」という表現に置き換えられる。その結果、このマクロが埋め込まれたプログラム箇所が実行されるたび
「ERROR ファイル名　行番号」
という表示がコンソールに表示されることとなる。こんなうまい手を使わないことがあるだろうか？！
そういう性質のテクニックなので、C言語を使う者であれば比較的初級者でもこの方法を知っていることが少なくない。

ではこれを、Rubyでも行おうとしたらどうすれば良いだろうか？　前述したとおり、Rubyにプリプロセッサなどというものはない。まず安直に考えて以下のコードはとりあえず、機能はする。

print "ERROR  #{__FILE__} #{__LINE__}"

__FILE__　と　__LINE__ はRubyでは擬似変数とい扱いとされている。これを先ほどのC言語のように、いちいち __FILE__, __LINE__ と書かないでも出力されるようにしたい。

だが結論から言うと、__FILE__, __LINE__ をそのまま使う方法では大変厳しく、恐らく不可能に近いだろう。なぜならこの２つの擬似変数は上述したC言語のマクロのように、ソースコードに現れた箇所のファイル名と行番号をそのまま返すので、ソースコード上に直接埋め込む以外に原則、使いようがない。だからプリプロセッサのないRubyで__FILE__, __LINE__ を書かずにファイル名と行番号を出そうとしても無理だ。

そこで発想を変えてみる必要がある。Rubyにおいて実行中のファイルや行番号といった情報はどこから手に入るのか？　それらの一つにKernelモジュールのcaller というメソッドがある。caller を用いて適当なメソッドを書くとすれば大概以下のようなものではないだろうか。

def print_message( msg )
  p  "#{msg}  #{caller[0]}"
end

Kernel.#callerメソッドはその名の通り、callerメソッド自身を呼び出しているメソッドを再帰的に表現した配列を返す。言い換えればスタックトレースを入手するためのメソッドで、戻り値の配列を添え字の小さい方から大きい方へと走査することで、丁度スタックを巻き戻すように呼び出し元メソッドの情報（ファイルと呼び出し行番号）を得ることができる。

仮に以下の内容のファイル abc.rb を用意したとしよう。(※左端の数字は行番号)

     1 # coding: utf-8
      2
      3 def aaa
      4 puts  caller[0]
      5 end
      6
      7 def bbb
      8   aaa
      9 end
     10
     11 def ccc
     12  puts caller[0]
     13 end
     14
     15 def ddd
     16   ccc
     17 end
     18
     19 aaa
     20
     21 bbb
     22
     23 ccc
     24
     25 ddd
     26

これを実行すると以下の実行結果が得られるはずだ。

> ruby abc.rb
abc.rb:19:in `
'
abc.rb:8:in `bbb'
abc.rb:23:in `
'
abc.rb:16:in `ddd'

caller[0] は「メソッド自身(caller)を呼び出しているメソッドの呼び出されている場所」を示している。だから19行目でメソッドaaa が呼び出されると、aaa内部のcaller[0]はaaaが呼び出された場所、すなわち abc.rb の19行目という情報を返す。

こうしたKernel.#callerの応用は独自定義の例外クラスを定義する際にも用いることができる。initializeメソッドの内部でcallerを使うことで例外の送出位置を知ることができれば、例外が起きたときの調査・分析にかかる時間を短縮できるだろう。

class MyException < Exception
  attr_reader :raised_at
  def initialize(*args)
     super
     @raised_at = caller[0]
   end
end

全てのクラスに何らかの位置捕捉情報を持たせたければObjectクラスを再定義すればよい。

# coding: utf-8

class Object
  def source_location
    caller[0]
  end
end


h = {a:1, b:2}
p h                          # => {:a=>1, :b=>2}
p h.source_location  # => "aaa.rb:12:in `
'" 

ここに挙げたコードは思いついたままのほんの一例に過ぎないが、アイディア次第ではデバッグ等に重宝するのではないだろうか。