【中級者への道】Rubyのいろいろなデバッグ方法

Ruby Advent Calendar 2019 の14日目を担当させていただきます。自称Ruby中級者です。
僕は養鶏業界から独学でRubyを学びこの業界に来たズブの素人です。
なので間違えているところがあれば遠慮せず指摘していただけると幸いです。
あと、冒頭にちょっと余談があります。

余談

いきなり余談です。僕がちょうどRubyを独学で勉強し始めた頃(2年くらい前)から、初学者の言語選択においてRubyが選ばれることが多いなと感じています。2年くらい前から急にというわけではなくて、僕がこの業界に興味を持った頃には既に初学者におけるRubyの人気は高いものになっていました。その理由として、やはりRailsの存在があがってきます。これに関してはあまりいい意味で人気があるとはいえず、言語やWebの基礎理解がないままアプリケーションが作れてしまうという意味で人気なのだろうと思います。僕自身も例に漏れず、Railsの便利すぎる危険な側面にどっぷりとハマってしまい、「なんかよくわからんけどアプリケーションできた！ウェイ！」と基礎理解がないままアプリケーションを作成し、「Railsしかできない」「わかった気になっただけ」のポンコツ人材として転職活動を行なっていました。同じような状態の初学者、初心者は多く存在する印象で、そういう人ほど長い期間「初心者」を名乗り続けています。

初心者を名乗っている方がいればよく思い出して欲しいのですが、何かアプリケーションを作っていて詰まった時、「エラーメッセージに書いてある意味はわかる、なんとなくこのあたりがおかしいんだろうけど、どうやってそれを特定するのかがわからない。どうやって確認すればいいんだろう？」と思ったことはありませんか？それを解決するのがいわゆるデバッグなのです。

ちなみに「なんかエラーが出た。」としか思わないというあなた！ちゃんとエラーメッセージを読んでくださいね。僕は外から来た比較的新しい人間なのでまだ優しいですが、この業界の人たちはエラーメッセージを読まない、エラーメッセージで検索して意味を理解しようとしない人に対する反応はとても厳しいです。

  tmp/sample.rb:15:in `foo': undefined method `bar' for nil:NilClass (NoMethodError)
# ^^^^^^^^^^^^^ ^^     ^^^   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^  ^^^^^^^^^^^^^
#        ①      ②      ③                        ④                         ⑤

① エラーの発生したファイル(場所)
② エラーの発生した行番号(場所)
③ エラーの発生したメソッド名(場所)
④ エラーの説明(原因)
⑤ エラーの種類(例外クラス)

どんなエラーがなぜ起きたのかについては④⑤を読んだり調べたりすれば分かります。
実際にデバッグする場所は①②③を頼りに探します。

デバッグあれこれ

話が逸れてしまいましたが、今回はそのデバッグで使える僕の知る限りのテクニック¹を基礎の基礎から説明していきたいなと思います。基本的に上にあればあるほど簡単なものになっています。皆様の自走の手助けになれば幸いです。

pメソッド、ppメソッド

pメソッドやppメソッドはオブジェクトを見易く出力するメソッドです。デバッグの基本は出力して確認することです。気になる物はとにかく出力してみましょう。中身のよくわからない変数や戻り値がよくわからないメソッド呼び出しがあれば片っ端から出力して確認するのです。
出力といえばputsメソッドが思い浮かぶと思いますが、違いがわかりやすいのが文字リテラルを出力する場合です。

obj = '12345'

puts obj
# 12345

p obj
# "12345"

pp obj
# "12345"

pやppメソッドで出力すると、文字リテラルは""で囲われた状態で出力されるので何のオブジェクトなのかが分かりやすいです。pとppの使い分けですが、pに比べてppメソッドは、必要があれば適切な改行やインデントで成形されて出力されるので、巨大なオブジェクトを出力する場合に適しています。Ruby2.5以降であればrequireなしでもppが使えるので、初めのよくわからない内はとりあえずppメソッドを使っていてもいいと思います。

tapでメソッドチェーンの途中の状態を探る（追記）

出力の応用でメソッドチェーンの途中の状態を出力して確認できます。

['48656c6c6f2052756279'].pack('H*').split.last
#=> 'Ruby'

ぱっと見よくわからないですよね(わざとそう書いてるんですが)。

['48656c6c6f2052756279'].pack('H*')

の部分で何が返ってるのか調べたい時にtapが有効です。
Object#tapはブロック変数にレシーバ自身を取り、戻り値もレシーバが返ります。

['48656c6c6f2052756279'].pack('H*').tap { |obj| p obj }.split.last
# "Hello Ruby"
#=> 'Ruby'

tapの時点のレシーバが出力されています。

p ['48656c6c6f2052756279'].pack('H*')

とするのと結果は同じですが、メソッドチェーン中の気になる部分にtapを差し込むだけでその時点の出力ができるので簡単で便利です。

['48656c6c6f2052756279'].pack('H*').tap { |obj|
  p obj.class
  p obj.unpack('B*')
}.split.last
# String
# ["01001000011001010110110001101100011011110010000001010010011101010110001001111001"]
#=> 'Ruby'

ブロック内で色々試したり遊んだりできます。楽しい。

.tap { |obj| p obj }の記述は.tap(&method(:p))と書けたりもします。
2.7以降であれば Numbered parameter の登場で.tap{p _1}と書けるみたいですね。
_1は第一仮引数部分を参照していますが、本題とは関係ないので詳しい解説は省略します。

irbを起動する

コードの任意の場所でirbを起動できます。
irbとは標準入力からRubyの式を入力でき、即座に実行結果を確認できる機能です。

def sample(x, y)
  binding.irb
end

sample('foo', 'bar')

    1: def sample(x, y)
 => 2:   binding.irb
    3: end
    4: 
    5: sample('foo', 'bar')

> x
#=> 'foo'
> y
#=> 'bar'
> x + y
#=> "foobar"

これはsample('foo', 'bar')が実行される時のsampleメソッド内でirbを起動しています。なので、引数に何が渡っているのかなどを確認できます。
binding.irbを記述した部分で止まるので、任意の箇所で任意のRubyの式を実行してみたい時に大活躍ですね。出力と比べてirbの方がその場で色々と試せるので柔軟性はこちらの方が高いです。

オブジェクトの正体を調べる

変数に入っているオブジェクトやメソッドを呼び出した戻り値のオブジェクトが何なのか調べるときに使います。恐らく一番よく使うことになるテクニックかなと思います。

class A
  def initialize; end
end

module M
  def hoge; end
end

class B < A
  include M

  def foo
    'sample'
  end

  private
    def bar; end
end

obj = B.new

obj.class
#=> B
# obj は B クラスのオブジェクト

obj.foo.class
#=> String
# B#foo メソッドの戻り値は String クラスのオブジェクトになる

obj.class.ancestors
#=> [B, M, A, Object, Kernel, BasicObject]
# B クラスは自身以外に M, A, Object, Kernel, BasicObject のクラスまたはモジュールを継承やインクルードしている

obj.public_methods
#=> [:foo, :hoge, :instance_variable_set, :instance_variable_defined?, :remove_instance_variable, :instance_of?, :kind_of?, :is_a?, :tap, :instance_variable_get, :public_methods, :instance_variables, :method, :public_method, :define_singleton_method, :public_send, :singleton_method, :extend, :pp, :to_enum, :enum_for, :<=>, :===, :=~, :!~, :eql?, :respond_to?, :freeze, :inspect, :object_id, :send, :to_s, :display, :nil?, :hash, :class, :singleton_class, :clone, :itself, :dup, :taint, :yield_self, :untaint, :tainted?, :untrusted?, :untrust, :frozen?, :trust, :methods, :singleton_methods, :protected_methods, :private_methods, :!, :equal?, :instance_eval, :==, :instance_exec, :!=, :__id__, :__send__]
# 呼び出し可能なメソッドの一覧
# プライベートメソッドが含まれていないところがポイント
# ちなみにこの長い配列を p メソッドで出力するとそのまま、pp メソッドで出力するとメソッドごとに改行されて出力される

obj.public_methods(false)
#=> [:foo]
# 引数にfalseを渡すと、自分のクラスが持つメソッドのみの配列になる

特に戻り値のクラスを調べるという場面が多いです。

callerでメソッドの呼び出し元を探る

メソッドの中でcallerを呼び出すと、そのメソッドがどこで呼び出されているかがわかる。

class A
  def initialize; end
  def foo
    p caller
  end

  def bar
    foo
  end

  def piyo
    bar
  end
end

p self
#=> main

obj = A.new

obj.foo
# ["debug.rb:21:in `<main>'"]
# foo メソッドは21行目の main から呼ばれている。
# main -> fooメソッド

obj.piyo
# ["debug.rb:8:in `bar'", "debug.rb:12:in `piyo'", "debug.rb:26:in `<main>'"]
# foo メソッドは8行目のbarメソッドから呼ばれている
# main -> piyoメソッド -> barメソッド -> fooメソッド

そのメソッドがどのメソッドを経由しながらどこから呼ばれかのかがわかります。経由してきたメソッドを遡ってさらにデバッグすることでバグの原因を探す手がかりとなります。

method(:foo).source_location でメソッドの定義場所を探る

出てきたメソッドがどこで定義されているかわからないときに用いるテクニックです。コードエディタには基本的にコードジャンプ機能が付いているので、これをわざわざ使う場面というのはあまりないかと思いますが、知っていれば役に立つ時が来るかも...？

class A
  def initialize; end
  def foo
  end
end

obj = A.new

p obj.method(:foo).source_location
# ["debug.rb", 3]
# fooメソッドは debug.rb の3行目に定義されている。

グローバル変数が書き換えられている場所を探す

グローバル変数の書き換えられた場所探すの大変だからね。

trace_var(:$FOO) { p caller.first }
# これ以降グローバル変数 $FOO の最初の代入から値が書き換えられた場所を出力する

$FOO = 'foo' # 最初の代入
$FOO = 'bar'
$FOO.concat 'piyo'

# "debug.rb:5:in `<main>'"
# "debug.rb:6:in `<main>'"
# 5行目と6行目でグローバル変数の書き換えが発生

メモリ上のオブジェクト数をカウントする

パフォーマンスとか負荷とか考えるときに使うんですかね。これに関しては使う場面がよくわからないのでわかる方がいれば教えてください。

GC.start

ObjectSpace.each_object(Hash).count
# メモリ上に残っている Hash オブジェクトの数をカウント

TracePointを使う

ここまで来るとよほど複雑なデバッグを要求されない限りは趣味の領域なのでは...とすら思う。

indent = 0
trace = TracePoint.new(:call, :return) do |tp|
  if tp.event == :return
    print ' ' * indent
    puts "<= #{[tp.defined_class, tp.method_id].inspect}"
    indent -= 2 if indent > 0
  else
    print ' ' * indent
    p [tp.defined_class, tp.method_id]
    indent += 2
  end
end

trace.enable

# ...

trace.disable

# ...の部分に書いたコードで呼ばれるメソッドが全て出力されます。ほんの少量のコードでもとんでもない数のメソッド呼び出しが行われていることがわかります。

最後に

最後の方のテクニックはともかく、クラスの正体を調べるテクニックあたりまでは身につけておいて損はないかなと思います。手順を完璧に覚える必要はなくて、そういうテクニックがあったなというのを頭の片隅にでも覚えておくことが重要です。手順を忘れた時はこの記事を読み返しにきてください。

学習を始めた最初のうちは、わからないことが多く、周りを頼っても対応が冷たく感じたり、当たりが強く感じることもあるかと思います。しかしこの業界の人たちは向上心のある初学者を決して見捨てないですし、本当にその人のためを思ってアドバイスしてくれます。特にRuby界隈の人は人情に溢れ親身で優しい人がとても多い(らしい)です。人の指摘は真摯に受け止めて、努力する姿勢が大切です。ちょっとわかるようになってくると一気に楽しくなるので頑張りましょう。僕も頑張ります。

---

1. RubyKaigi2019でNaClさんが配布してくださったRubyDebugCheatSheetを参考 ↩