大変なバグというか出力データ内のバグというか

TCC というコンパイラをいじって遊んでいるのですが、簡単なバグから潰しているので、だんだんと混み入ったバグになってきました。今いじっているのは、

./tcc tcctest.c && ./a.out

として実行した結果と、

./tcc -DTCC_TARGET_X86_64 tcc.c -ldl -g -o tcc2
./tcc2 tcctest.c && ./a.out

などとして tcc で自身をコンパイルして、それでできた tcc2 を使って tcctest.c を実行した結果で、結果が違うというものです。

問題となっているテストケースは printf もどきを test 内で実装して、 stdarg がきちんと動作しているかを確認するようなテストケースでした。

実際コードを見てみると、確かに生成されている printf もどきのコードは微妙に違っていて、まぁそれはヘンだなぁと生成されたコードの差分を見てみると、

-       48 89 d0                mov    %rdx,%rax
-       48 01 c1                add    %rax,%rcx
+       48 01 d1                add    %rdx,%rcx

という感じになっています。オリジナルの方は %rax 経由で迂回しているけど、 tcc2 の方は %rax を通らずそのまま加算していて、どう見ても tcc2 の方が良いコードに見えます。で、この mov やら add が C コードのどの部分と対応しているか、を調べるのは objdump 一発で簡単なんですが、この mov やら add を生成したのは TCC 内のどの部分か、ということになるとかなり難しくなります。

無理にやるとすると、コードを生成するたびにそのコードの位置と backtrace を保存しておいて、そのコードの位置と backtrace を見比べて場所を特定する…とかになるんでしょうか。追記: コメントで指摘いただきましたが、ここは condition つきの break すればいいだけなのでおかしいです。まぁいずれにせよ tcc2 の方はそんな高度なことができないので、処理の違いを追うことができないのですが。

いずれにせよ、このコードの変化によって動作結果が変わるようには思えません。でも他に printf もどきに変化はありませんでした。

ということは printf を呼ぶ側の方かなぁ…と、あれこれいじってみると、

long double ld = 1.2L;
int main(int a) {
    printf("%llf\n", ld);
}

というようなコードから出力されるバイナリが、サイズは一致して、実行コードも完全に一致しているものの、 cmp コマンドで調べると差分があるということでした。 ELF の情報がおかしいのかなぁ、と

> diff =(readelf -a t1.o) =(readelf -a t2.o)

などとしてみてみ何も出ません。じゃあ hex dump で比較してみるか、と

> diff =(od t1.o) =(od t2.o)
9c9
< 000080 9a 99 99 99 99 99 99 99 ff 3f 00 00 00 00 00 00  >.........?......<
---
> 000080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  >................<

などとして、差分のアドレスを特定しました。で、 objdump -x を使うと、

Sections:
Idx Name          Size      VMA               LMA               File off  Algn
  0 .text         0000003d  0000000000000000  0000000000000000  00000040  2**5
                  CONTENTS, ALLOC, LOAD, RELOC, READONLY, CODE
  1 .data         00000016  0000000000000000  0000000000000000  00000080  2**5
                  CONTENTS, ALLOC, LOAD, DATA
  2 .bss          00000000  0000000000000000  0000000000000000  000000a0  2**5
                  ALLOC

とのことで、 000080 はどうやら .data セクション内のようです。 9a9999..ff3f とかいう列が tcc2 の吐いた方の出力には無いみたいで、これはおそらく long double の 1.2 という値をエンコードした値だろうな、と見当がつきます。

これで、 long double 関係の何かが悪いことがわかります。さっきの迂回する件よりは多少マシですが、何が悪いかはまだ見当もつきません。

さて、この状況だとデバッガとか使える気とかしません。 tcc2 は tcc が出力したバイナリなので、デバッグ情報ををロクに残してないですし、オリジナルの tccgdb を使うとしてもバグの位置なんて見当もつかないからです。

で、 printf 入れて tcc2 を作りなおします。幸い tcc で作るので 0.05秒で終わります。とりあえずリテラルの読み込み部分は大丈夫かねえ、と、数値の parse の部分に、

            } else if (t == 'L') {
                ch = *p++;
                tok = TOK_CLDOUBLE;
                tokc.ld = strtold(token_buf, NULL);
                printf("%llf\n", tokc.ld);

とか適当に入れて tcc2 を作りなおして、その tcc2 を使って 1.2L を含むソースコードを読ませてみました。すると今回は一発でビンゴで、 0.0 とか表示されまして、ああなるほど strtold の返り値がぶっこわれてるか、 printf に long double がうまくわたってないからだなぁとわかりました。

でまぁ、 printf を long double を引数にして呼ぶ方は十分にテストされてるし、 long double を返す関数を使ったテストも tcctest.c 内にはあるので、何かなぁと思ったのですが、 strtold のように GCCコンパイルされた関数から long double を返して受け取るテストは無いなぁと思い、(中略)調べてみたところやはりそれが悪かったようで、 ABI が GCC とコンパチにできてなかったのでした。

とまぁ、わかればすぐ修正できるようなバグをちまちまと修正するわけですが、 tcc が生成した tcc2 というデバッグ情報が不十分なので、出力データと言って良いような物体を使って始めて起きるバグとかになると、なかなか大変な感じです。

こういう、正常終了したけど、出力したものがなんかおかしい、っていう種類のバグは割と大変なケースが多い気がします。出力した物体には実行のコンテキストが全く残ってないのが問題だと思います。こういうケースだと、適当に printf ばらまいて、出力データとごちゃ混ぜに出力してしまって、その結果をぼーと眺めて当たりをつける、とか、問題となってるデータを出力してそうな部分に、問題となっているデータぽいものが来たら 0xcc を通るようにヘンな if 文を書いてデバッガで止めたりとかしたりするんですが (conditional break じゃ無理な程度には複雑な条件) 、デバッガ原理主義な人はどうするんかいなぁとか思うのでした。

それはともかく、今回のバグはとりあえず潰れたぽいので、次は

> ./tcc -run -DTCC_TARGET_X86_64 tcc.c tcctest.c

としたら SEGV してしまうバグを潰したいです。 -run オプションというのは、コンパイルの後にバイナリを出力せずに、メモリ内で main を実行するようなオプションです。 SEGV と言えば gdb 、と思うわけですが、今回の場合、実行時に生成されたコードであるため、 gdb でも

(gdb) bt
#0  memcpy () at ../sysdeps/x86_64/memcpy.S:162
#1  0x00007f7f5878c008 in ?? ()
#2  0x00007fff608e64c0 in ?? ()
#3  0x00007f7f587be88d in ?? ()
#4  0x00007f7f587be85d in ?? ()
#5  0x00007f7f587be85d in ?? ()

とかいうスタックトレースしか得られなかったりします。こういうシーンでもまぁ gdb より printf の方がまだマシなケースも多くて、実際 Yajit いじってる時なんかは gdb も使いましたけどそれ以上に printf しまくっていたように思います。

まぁでも今回はデバッガにアドレスの調整つきでシンボルテーブルを喰わせられる方法があれば、別に実行バイナリを作ってそのシンボルを喰わせれば場所の特定くらいはラクにできそうに思いますし、まぁそんなニッチな機能は無いのは当然としても死んだアドレスから手動で計算して実行バイナリと比較すれば情報が増えるので、もちろん gdb もお役立ちではあるんですけど。

まぁなんかこの手のものデバッグする時にいい方法無いもんかなーとかここ1年くらい思ってる気がします。

なにかあれば下記メールアドレスへ。
shinichiro.hamaji _at_ gmail.com
shinichiro.h