debugging.asc

Git によるデバッグ

Git には、プロジェクトで発生した問題をデバッグするためのツールも用意されています。 Git はほとんどあらゆる種類のプロジェクトで使えるように設計されているので、このツールも非常に汎用的なものです。しかし、バグを見つけたり不具合の原因を探したりするための助けとなるでしょう。

ファイルの注記

コードのバグを追跡しているときに「それが、いつどんな理由で追加されたのか」が知りたくなることがあるでしょう。そんな場合にもっとも便利なのが、ファイルの注記です。 これは、ファイルの各行について、その行を最後に更新したのがどのコミットかを表示します。 もしコードの中の特定のメソッドにバグがあることを見つけたら、そのファイルを git blame しましょう。そうすれば、そのメソッドの各行がいつ誰によって更新されたのかがわかります。 この例では、-L オプションを使って 12 行目から 22 行目までに出力を限定しています。

$ git blame -L 12,22 simplegit.rb
^4832fe2 (Scott Chacon  2008-03-15 10:31:28 -0700 12)  def show(tree = 'master')
^4832fe2 (Scott Chacon  2008-03-15 10:31:28 -0700 13)   command("git show #{tree}")
^4832fe2 (Scott Chacon  2008-03-15 10:31:28 -0700 14)  end
^4832fe2 (Scott Chacon  2008-03-15 10:31:28 -0700 15)
9f6560e4 (Scott Chacon  2008-03-17 21:52:20 -0700 16)  def log(tree = 'master')
79eaf55d (Scott Chacon  2008-04-06 10:15:08 -0700 17)   command("git log #{tree}")
9f6560e4 (Scott Chacon  2008-03-17 21:52:20 -0700 18)  end
9f6560e4 (Scott Chacon  2008-03-17 21:52:20 -0700 19)
42cf2861 (Magnus Chacon 2008-04-13 10:45:01 -0700 20)  def blame(path)
42cf2861 (Magnus Chacon 2008-04-13 10:45:01 -0700 21)   command("git blame #{path}")
42cf2861 (Magnus Chacon 2008-04-13 10:45:01 -0700 22)  end

最初の項目は、その行を最後に更新したコミットの SHA-1 の一部です。 次のふたつの項目は、そのコミットから抽出した作者情報とコミット日時です。これで、いつ誰がその行を更新したのかが簡単にわかります。 それに続いて、行番号とファイルの中身が表示されます。 ^4832fe2 のコミットに関する行に注目しましょう。これらの行は、ファイルが最初にコミットされたときのままであることを表します。 このコミットはファイルがプロジェクトに最初に追加されたときのものであり、これらの行はそれ以降変更されていません。 これはちょっと戸惑うかも知れません。Git では、これまで紹介してきただけで少なくとも三種類以上の意味で ^ を使っていますからね。しかし、ここではそういう意味になるのです。

Git のすばらしいところのひとつに、ファイルのリネームを明示的には追跡しないということがあります。 スナップショットだけを記録し、もしリネームされていたのなら暗黙のうちにそれを検出します。 この機能の興味深いところは、ファイルのリネームだけでなくコードの移動についても検出できるということです。 git blame に -C を渡すと Git はそのファイルを解析し、別のところからコピーされたコード片がないかどうかを探します。 例えば、GITServerHandler.m というファイルをリファクタリングで複数のファイルに分割したとしましょう。そのうちのひとつが GITPackUpload.m です。 ここで -C オプションをつけて GITPackUpload.m を調べると、コードのどの部分をどのファイルからコピーしたのかを知ることができます。

$ git blame -C -L 141,153 GITPackUpload.m
f344f58d GITServerHandler.m (Scott 2009-01-04 141)
f344f58d GITServerHandler.m (Scott 2009-01-04 142) - (void) gatherObjectShasFromC
f344f58d GITServerHandler.m (Scott 2009-01-04 143) {
70befddd GITServerHandler.m (Scott 2009-03-22 144)         //NSLog(@"GATHER COMMI
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 145)
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 146)         NSString *parentSha;
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 147)         GITCommit *commit = [g
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 148)
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 149)         //NSLog(@"GATHER COMMI
ad11ac80 GITPackUpload.m    (Scott 2009-03-24 150)
56ef2caf GITServerHandler.m (Scott 2009-01-05 151)         if(commit) {
56ef2caf GITServerHandler.m (Scott 2009-01-05 152)                 [refDict setOb
56ef2caf GITServerHandler.m (Scott 2009-01-05 153)

これはほんとうに便利です。 通常は、そのファイルがコピーされたときのコミットを知ることになります。コピー先のファイルにおいて最初にその行をさわったのが、その内容をコピーしてきたときだからです。 Git は、その行が本当に書かれたコミットがどこであったのかを (たとえ別のファイルであったとしても) 教えてくれるのです。

二分探索

ファイルの注記を使えば、その問題がどの時点で始まったのかを知ることができます。 何がおかしくなったのかがわからず、最後にうまく動作していたときから何十何百ものコミットが行われている場合などは、git bisect に頼ることになるでしょう。 bisect コマンドはコミットの歴史に対して二分探索を行い、どのコミットで問題が混入したのかを可能な限り手早く見つけ出せるようにします。

自分のコードをリリースして運用環境にプッシュしたあとに、バグ報告を受け取ったと仮定しましょう。そのバグは開発環境では再現せず、なぜそんなことになるのか想像もつきません。 コードをよく調べて問題を再現させることはできましたが、何が悪かったのかがわかりません。 こんな場合に、二分探索で原因を特定することができます。 まず、git bisect start を実行します。そして次に git bisect bad を使って、現在のコミットが壊れた状態であることをシステムに伝えます。 次に、まだ壊れていなかったとわかっている直近のコミットを git bisect good [good_commit] で伝えます。

$ git bisect start
$ git bisect bad
$ git bisect good v1.0
Bisecting: 6 revisions left to test after this
[ecb6e1bc347ccecc5f9350d878ce677feb13d3b2] error handling on repo

Git は、まだうまく動いていたと指定されたコミット (v1.0) と現在の壊れたバージョンの間には 12 のコミットがあるということを検出しました。そして、そのちょうど真ん中にあるコミットをチェックアウトしました。 ここでテストを実行すれば、このコミットで同じ問題が発生するかどうかがわかります。 もし問題が発生したなら、実際に問題が混入したのはそれより前のコミットだということになります。そうでなければ、それ以降のコミットで問題が混入したのでしょう。 ここでは、問題が発生しなかったものとします。git bisect good で Git にその旨を伝え、旅を続けましょう。

$ git bisect good
Bisecting: 3 revisions left to test after this
[b047b02ea83310a70fd603dc8cd7a6cd13d15c04] secure this thing

また別のコミットがやってきました。先ほど調べたコミットと「壊れている」と伝えたコミットの真ん中にあるものです。 ふたたびテストを実行し、今度はこのコミットで問題が再現したものとします。それを Git に伝えるには git bisect bad を使います。

$ git bisect bad
Bisecting: 1 revisions left to test after this
[f71ce38690acf49c1f3c9bea38e09d82a5ce6014] drop exceptions table

このコミットはうまく動きました。というわけで、問題が混入したコミットを特定するための情報がこれですべて整いました。 Git は問題が混入したコミットの SHA-1 を示し、そのコミット情報とどのファイルが変更されたのかを表示します。これを使って、いったい何が原因でバグが発生したのかを突き止めます。

$ git bisect good
b047b02ea83310a70fd603dc8cd7a6cd13d15c04 is first bad commit
commit b047b02ea83310a70fd603dc8cd7a6cd13d15c04
Author: PJ Hyett <pjhyett@example.com>
Date:   Tue Jan 27 14:48:32 2009 -0800

    secure this thing

:040000 040000 40ee3e7821b895e52c1695092db9bdc4c61d1730
f24d3c6ebcfc639b1a3814550e62d60b8e68a8e4 M  config

原因がわかったら、作業を始める前に git bisect reset を実行して HEAD を作業前の状態に戻さなければなりません。そうしないと面倒なことになってしまいます。

$ git bisect reset

この強力なツールを使えば、何百ものコミットの中からバグの原因となるコミットを数分で見つけだせるようになります。 実際、プロジェクトが正常なときに 0 を返してどこかおかしいときに 0 以外を返すスクリプトを用意しておけば、git bisect を完全に自動化することもできます。 まず、先ほどと同じく、壊れているコミットと正しく動作しているコミットを指定します。 これは bisect start コマンドで行うこともできます。まず最初に壊れているコミット、そしてその後に正しく動作しているコミットを指定します。

$ git bisect start HEAD v1.0
$ git bisect run test-error.sh

こうすると、チェックアウトされたコミットに対して自動的に test-error.sh を実行し、壊れる原因となるコミットを見つけ出すまで自動的に処理を続けます。 make や make tests、その他自動テストを実行するためのプログラムなどをここで実行させることもできます。