私がめんどくさがって Debug.Print を挟みまくる理由

私の場合はグローバル変数インスタンス変数、それの集合体であるビジネスロジックの状態が目まぐるしく変化するクソコードを相手にすることが多く、
普通のブレークポイントを置いて F10 や F11 を押してステップごとに変数の値を確認するというようなごくふつうのぷよぐらまーがやるような正攻法のデバッグの仕方では
どうしてもプログラムの流れを掴むことができないということが往々にしてあるのである。

これは、私の限界なのかもしれないが、限界とはいえ、別の方法があるのなら、やるべきである。
そこで私は Debug.Print() を挟む:

var result = engine.GetHoge( piyo, fuga, doge );
if ( result.IsFail ) {
    Debug.Print( "ほげの取得に失敗しました。" );
    Debug.Print( "{0}: {1}", result.Status, result.Message );

    return ;
}

ここで Debug.Print() は本来の処理には全くかかわらないようにするべきである。
当然なんだけどね。

トレースログに、「ほげの取得に失敗しました」と書いてあれば、ほげの取得に失敗したことがわかるし、 2 行目にステータスとメッセージを表示しているので多分その理由が書いてあるはず。
ここまではブレークポイントを張ってデバッグして実行しても分かることだ。

ブレークポイントを張ってデバッグして実行するだけでは分からないバグというのがあって、1 回目は普通に何でも無く通るんだけど、 何回か通った後に何らかの原因で発現するバグには歯が立たないこともある。
今は条件ブレークポイントとか、便利なものがあるけれど、それが使えるのはどんな条件で発現するのか見当がついている時だけだ。
見当もつかない時はデバッグプリントの出番だ。
バグが GetHoge() を実行した後に出る*1ならこんな風にする:

Debug.WriteLine( piyo, "piyo" );
Debug.WriteLine( fuga, "fuga" );
Debug.WriteLine( doge, "doge" );

var result = engine.GetHoge( piyo, fuga, doge );
if ( result.IsFail ) {
    Debug.Print( "ほげの取得に失敗しました。" );
    Debug.Print( "{0}: {1}", result.Status, result.Message );

    return ;
}

GetHoge() に渡す引数がおかしいのかもしれない。
そう思って GetHoge() に渡す 3 つの引数を表示してみることにした。
ここで分かればいいのだが、現実にはそういうことはあんまり無いだろうから、デバッグプリントを挟む作業はまだまだ続く。
もうちょっといい例を出せれば良いんだけど。

そういえば、デバッグプリントは実行時間が長いプログラムにはめちゃくちゃ効果を発揮したりする。
実行してから 1 時間後にバグの前兆が出て、その 2.5 時間後にバグがこの世に顕現するというような場合にはブレークポイントを張って待機するというようなモダンなやり方は私には根気が続かないのだ。

それから、考えただけであんまりやらない実行時チェックというのも考えた。

Debug.Print("1..1");

var hoge = 1;
var piyo = 1;

var fuga = hoge + piyo;

Debug.WriteIf( 2 != fuga, "not " );
Debug.WriteLine( "ok 1 - 1 足す 1 は 2" );

実行時にトレースログに TAP なチェック結果を出力すると云うものだ。
結構楽しいからデバッグプリントいいよ。

参考

*1:ここでは例外が送出されたり、何か不思議なことが起きる