スクリーンショット_2016-06-06_17.53.52

無限ループのデバッグ

https://gist.github.com/teramotodaiki/efac6b29a1b063639661ed55e9e5b9fe/revisions

上のコードは迷路を自動生成するアルゴリズムである。

今回の問題は、この迷路生成の計算が終わらないということから始まった。原因はすでに判明しているが、revisionsの一番古いコードをhackforplayに貼り付けるとそれが確認出来る(ブラウザのタブがクラッシュするので、試すのはおすすめしない)。


無限ループから抜け出そう

このアルゴリズムには、十数個のwhile文が使われている。まずは、このうちのどれかが無限ループになっている、という仮説を立てた。どのループが原因になっているのかを調べるために、まずは怪しそうなループを全て「繰り返さないループ」に差し替えることにしよう。

ここで紹介することは、Gistの2つ目の更新に実際のコードがある。僕のつたない日本語よりもJavaScriptが読みやすいという方は、ぜひそちらをご覧いただきたい。

例えば、

do{ ... } while (count == 1000); 

という繰り返しのコードを 

do { ... } while (count == 1000 && false); 

にすることで、「繰り返さないループ」に差し替えることができる。

ここでひとつ工夫を加える。falseをそのまま付けるのではなく、 __stopper という関数にして、関数の結果として false を返す(returnする)ようにするのである。わざわざ関数を作る利点は2つある。

1.どこで使われたか分かるようにすること

2.true/false (ループさせる/させない)を切り替えられるようにすること

どこで使われたか分かるように、とは、一体どういうことだろうか。引数に適当な数字を入れてみると理解がしやすいかも知れない。先ほどの例はこうなる。

do { ... } while (count == 1000 && __stopper(1));

1というのは仮に入れた数字で、その他の条件式にはそれぞれ違った数字を入れておく。2, 3, ...とナンバリングしていけば分かりやすいだろう。

true/false を切り替えるには、return する値を変えてやれば良い。重要なのは、いつループさせていつ止めるかだが、それには色々な方法がある。ここでは時間を使った切り替えを用いることにする。

まずコードだ。

var __beginTime = new Date().getTime();
var __stopper = function (id) {

    var elapsed = new Date().getTime() - __beginTime;
    return elapsed < 1000;

};

解説すると、最初の行でゲームが始まったときの時間を残している。そして __stopper が使われたときの時間と比較している。

1000 という数字は例で、もしあなたの脳でシュミレートするのであれば、まずは 0 から始めてみると良い。0 では全ての場合で __stopper は false を返す。つまり全くループしない。1000 は 1000ミリ秒、つまり1秒のことなので、ゲームが開始されてから1秒経過するまでは __stopper は true を返す。つまり、この数字はループを止める時間を表している。

(__stopper はストッパーと読むのだが、 true の時は進ませて false の時はストップさせるので、むしろ __repeater かも知れない。こちらの話だ)

ひとまず、0 に設定してみた。するとどうだろう。うんともすんとも言わなかった迷路生成アルゴリズムが、動き出したのだ!(治ったわけではない、仕事を減らしただけだ)

これは何もすごいことをしたのではない。元々のアルゴリズムが良くできていたのである。では、どうしてさっきまでは動かなかったのだろうか?

次の章では、__stopper を使った原因究明のテクニックに迫る。


どこが「無限」の始まりだった?

無限ループに陥っている箇所を知るには、地道にループの回数を1回、2回と数えていくのが効果的だ。無限大という数字は当然数えられないが、他と比べてあまりにも大きいということはわかる。

var __beginTime = new Date().getTime();
var __dump = new Array(15).fill(0);
var __stopper = function (id) {

    var elapsed = new Date().getTime() - __beginTime;
    __dump[id] ++;
    return elapsed < 1000;

};
game.on('load', function () {
    console.log(__dump.join('\n'));
});

__stopper に、ループを数えるための処理を追加した。 __dump は 15 の長さを持つ配列であり、一つ一つの要素がそれぞれの __stopper に対応している。 id には 0〜14 の数字が入るというわけだ。

__dump[id] ++;

という箇所で、要素の数字を1増やしている。これは __stopper が呼び出された回数なので、つまりループの回数と同じになるはずである。

( && には短絡評価という特性があり、必ずしもループの度に __stopper が呼び出されるとは限らないのだが、今回は気にしない)

そして最後にそれを出力している。console.log はブラウザに備わっている開発者ツールというのを開くと確認できる。次のような結果が得られた。

0
33895
265
795
5232
36233
0
20
2003
134192
132
132
70
6
3

ちゃんと15個ある。そして、ループの深い部分(ループの中のループ)ほど数字が大きくなっていることもわかる(詳しくはGist参照)。

この中で最もループ回数が多いのは、134192回で9番だ。これが無限ループの元だろうか?−−実は、そうではない。本当の原因は、制限時間(1秒)のせいで隠れてしまっている。

ここからは実にコンピュータらしいやり方だ。数字を少しずつ増やしながらループ回数を数え、限界を探っていく。下に、結果のグラフを示す。

文字が小さくて申し訳ない。しかし結果は歴然である。グラフは右側に行くほど上限(ループを止める)時間が長くなり、縦軸はループ回数を表す。500ミリ秒くらいまでは拮抗しているが、その後は 13 だけが伸びている。

原因はどうやら13番にあるらしい。

平均にはあまり意味はないが、あえて平均するとこうなる。

13番だけが長い。ちなみに14番にも問題はあったのだが、13番で時間を使い切ってしまってしまうので、14番は一度も繰り返されなかった。

ここまで長い時間をかけたが、無限ループに陥っている箇所が判明した。


人間は過ちを犯すもの。だからデバッグをする

ここまででわかったことは、 13番のループはたくさん繰り返しているという、ただそれだけの事実である。

無限ループになってしまう原因はまた別にあるし、それもまたデバッグして原因を調べるしかない。原因が13番だけにあるとも限らない。ただちょっと遅いだけで、別のパソコンで動かしたら動いてしまう可能性だってある。

バグの原因なんて、99%はくだらない理由だ。スペルミスとか、コピペミスとか、== と === の違いとか、原因さえわかればすぐ治せてしまうことばかりだ。それなのに、原因を調べるには膨大な時間を要することもある。

デバッグを不毛に感じて、諦めてゼロから作り直すこともできる。それでも問題は解決するかも知れない。しかし、それでは人がデバッグをする本当の目的は達成されない。

我々は自らの過ちに気付くためにデバッグをするのである。

ちょっとした出来心で === を == と書いてしまっていた、その事実を認め、反省し、

「これからは === に統一しよう!」

そう自らの心に誓うまでがデバッグである。

もし自分を顧みることが出来なければ、あなたは一生 === と == を意図せず混同するコーディングライフを送ることになるだろう。職業プログラマでなければいい?デザイナや企画職なら許される?ハッ、そんなことを思っている人間は、何をしてもツメが甘いままだ!

自分の愚かさを認められない人間には、コンピュータも人間も扱えない。

デバッグの辛さから逃げ続けることはできない。あなたも幾度となく苦しむこととなるだろう。しかし、忘れないでほしい。この世に原因不明のバグはない。あなたがコンピュータと真摯に向き合い、デバッグをし続ける限り、いつかは光が射す時が来る。そんな時は、脳内でレベルアップのSEを流してあげよう。強いバグを倒した経験値は、はぐれメタル級に高いのだ。



この記事が気に入ったらサポートをしてみませんか?