$Id: segv.html,v 1.9 2002/10/24 18:37:50 aamine Exp $
この文書は 2002-10-24 の日記に書いていたのを単独ページに 移したものです。とある SEGV をデバッグする過程を記録しました。 デバッグ方法の参考にでもしてください。
TMail の質問メールが来た。 マルチパートメールを作るにはどうしたらいいのかという質問だ。 このへんのユーティリティメソッドは欲しいと思ってたので、 答えを書くついでにライブラリにも追加することにする。 書き終わって、それじゃあテストしようと思ったら、
~/r/tmail % t ....................................................... ..............F........................................ ..../home/aamine/lib/ruby/tmail/port.rb:161: [BUG] Segmentation fault ruby 1.7.3 (2002-09-13) [i686-linux] zsh: 1758 abort (core dumped) exectest
……というわけでデバッグを始めることにした。
tmail/port.rb:161 というと、ここだ。
def procinfostr( str, tag, true_p )
a = str.upcase.split(//)
この形はなんとなく見覚えがある。 以前、puts で落ちたときもこの形だった ([ruby-dev:18194])。 struct RString の ptr は 1.6 までは NULL にはならなかったのだけど、 1.7 の途中から NULL になるようになった。そのために最近いろいろな ところで SEGVっているのだ。
まずは何を置いてもスタックトレースを取る。 念のため最新版をコンパイルしてコアを作り直し、 gdb -c core ruby で bt。再現性があるバグだとこのへんが楽だ。
#0 0x40035431 in kill () from /lib/libc.so.6
#1 0x4003507e in raise () from /lib/libc.so.6
#2 0x4003672f in abort () from /lib/libc.so.6
#3 0x080dabb0 in rb_bug (fmt=0x80f8816 "Segmentation fault") at error.c:179
#4 0x080b766f in sigsegv (sig=11) at signal.c:412
#5 0x40035338 in sigaction () from /lib/libc.so.6
#6 0x0805d4d4 in call_cfunc (func=0x80c063c <rb_str_split_m>,
recv=1076716592, len=-1, argc=1, argv=0xbfff61a0) at eval.c:4393
#7 0x0805de73 in rb_call0 (klass=1074997592, recv=1076716592, id=4321,
oid=4321, argc=1, argv=0xbfff61a0, body=0x40132200, nosuper=1)
at eval.c:4530
#8 0x0805e8f8 in rb_call (klass=1074997592, recv=1076716592, mid=4321,
argc=1, argv=0xbfff61a0, scope=0) at eval.c:4746
#9 0x080583c3 in rb_eval (self=1076718772, n=0x4011c040) at eval.c:2739
#10 0x08059363 in rb_eval (self=1076718772, n=0x4011c02c) at eval.c:2912
#11 0x08056693 in rb_eval (self=1076718772, n=0x4011be88) at eval.c:2225
#12 0x0805e427 in rb_call0 (klass=1074819072, recv=1076718772, id=15073,
oid=15073, argc=0, argv=0xbfff70dc, body=0x4011be88, nosuper=0)
at eval.c:4656
：
：
：
ダーっと出るが、普通は SEGV をくらった sigaction の直前に 問題があることがほとんどである。従って後半は無駄なので捨ててよい。
今回は原因がかなりはっきり予測できてしまっているので簡単だ。 まず f (frame) で sigaction 直前の call_cfunc に移動し、
(gdb) f 6
#6 0x0805d4d4 in call_cfunc (func=0x80c063c <rb_str_split_m>,
recv=1076716592, len=-1, argc=1, argv=0xbfff61a0) at eval.c:4393
4393 in eval.c
レシーバ (recv) の値を確かめる。 ここのコードは str.split(//) なので文字列は recv 以外にないからだ (引数も文字列なら、そちらの ptr が NULL になっている可能性も考えられる)。 Ruby の文字列の実体は struct RString なので、それにキャストして p する。
(gdb) p *(struct RString*)recv
$1 = {basic = {flags = 8199, klass = 1074997592}, len = 0, ptr = 0x0, aux = {
capa = 1076716492, shared = 1076716492}}
予想通り ptr が NULL (0x0) である。十中八九、これをチェックしないで dereference したのが原因だろう。とすると、落ちたのは恐らく rb_str_split_m のどこかなのだが、シグナルをくらったために そのスタックフレームが一時的に上書きされたのだろう。 あとは rb_str_split_m のコードを見てレシーバの ptr をいじっている ところを洗えばよい。
static VALUE
rb_str_split_m(argc, argv, str)
int argc;
VALUE *argv;
VALUE str;
第三引数 str がレシーバだ。str を検索してハイライトさせ (less での話)、 ptr を検査なしで使っていないかざっと見る。
……と思ったのだけど、rb_str_split_m のコードは長いうえに 候補がいくつもあって嫌になった。方針を変えて、 最小SEGVコードを作ってみる。
まず ptr が NULL である文字列を用意する。 これは前回の SEGV のときに作りかたがわかっている。
" ".dup.rstrip.gsub(/a/, '')
で、ptr が NULL になる。これに対し split(//) すれば落ちるだろう。
~/s/ruby-g % cat null.rb ' '.dup.rstrip.gsub(/a/, '').split(//) ~/s/ruby-g % ./ruby null.rb null.rb:1: [BUG] Segmentation fault ruby 1.7.3 (2002-10-23) [i686-linux] zsh: 7357 abort (core dumped) ./ruby null.rb
目論見通り落ちる。
そうしたら今度はデバッガから動かして詳しいデータを取ろう。
~/s/ruby-g % gdb ./ruby GNU gdb 5.2.1 Copyright 2002 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "i686-pc-linux-gnu"...
rb_str_split_m にブレークポイントを設定する。
(gdb) b rb_str_split_m Breakpoint 1 at 0x80c0644: file string.c, line 2462.
んでスクリプトを走らせる。
(gdb) run null.rb
Starting program: /home/aamine/s/ruby-g/ruby null.rb
Breakpoint 1, rb_str_split_m (argc=1, argv=0xbffff2b0, str=1074943792)
at string.c:2462
2462 int awk_split = Qfalse;
ブレークポイントで止まった。 念のため str->ptr が NULL になっているのを確認。
(gdb) p *(struct RString*)str
$1 = {basic = {flags = 7, klass = 1074997592}, len = 0, ptr = 0x0, aux = {
capa = 0, shared = 0}}
バッチリ。 あとは落ちるまでバカみたいにトレースすればいい。 どうせすぐ落ちるでしょ。
(gdb) s
2463 long beg, end, i = 0;
(gdb)
2464 int lim = 0;
(gdb)
2467 if (rb_scan_args(argc, argv, "02", &spat, &limit) == 2) {
rb_scan_args は長そうだし str 関係ないので next に方針転換。
(gdb) n
2474 if (NIL_P(spat)) {
(gdb)
2483 if (TYPE(spat) == T_STRING && RSTRING(spat)->len == 1) {
(gdb)
2492 spat = get_pat(spat, 1);
(gdb)
2496 result = rb_ary_new();
(gdb)
2497 beg = 0;
(gdb)
2498 if (awk_split) {
(gdb)
2528 long start = beg;
(gdb)
2530 int last_null = 0;
(gdb)
2533 while ((end = rb_reg_search(spat, str, start, 0)) >= 0) {
(gdb)
2534 regs = RMATCH(rb_backref_get())->regs;
(gdb)
2535 if (start == end && BEG(0) == END(0)) {
そろそろヤバ気である。step に切り替えよう。
(gdb) s
2536 if (last_null == 1) {
(gdb)
2541 start += mbclen2(RSTRING(str)->ptr[start],spat);
(gdb) n
Program received signal SIGSEGV, Segmentation fault.
0x080c0973 in rb_str_split_m (argc=1, argv=0xbffff2b0, str=1074943792)
at string.c:2541
2541 start += mbclen2(RSTRING(str)->ptr[start],spat);
油断して next に変えた瞬間に落ちるのはやめてくだちい。 あ、でもこれは引数の RSTRING(str)->ptr[start] が原因なのか。 じゃあいいや。
というわけで string.c:2541 が SEGV の原因だとわかった。 あとは修正すりゃいいんだけど。うーん、こっちのほうがムズいぞ。 かなり適当な修正をしてみた。
~/s/ruby-g % vi string.c
~/s/ruby-g % cvs di string.c
Index: string.c
===================================================================
RCS file: /home/aamine/cvs/ruby/ruby/string.c,v
retrieving revision 1.122
diff -u -p -r1.122 string.c
--- string.c 23 Oct 2002 10:17:29 -0000 1.122
+++ string.c 24 Oct 2002 15:44:21 -0000
@@ -2533,7 +2533,11 @@ rb_str_split_m(argc, argv, str)
while ((end = rb_reg_search(spat, str, start, 0)) >= 0) {
regs = RMATCH(rb_backref_get())->regs;
if (start == end && BEG(0) == END(0)) {
- if (last_null == 1) {
+ if (!RSTRING(str)->ptr) {
+ rb_ary_push(result, rb_str_new("", 0));
+ break;
+ }
+ else if (last_null == 1) {
rb_ary_push(result, rb_str_substr(str, beg, mbclen2(RSTRING(str)->ptr[beg],spat)));
beg = start;
}
~/s/ruby-g % make ruby
gcc -g -pipe -I. -I. -c string.c
ar rcu libruby.a array.o bignum.o class.o compar.o dir.o dln.o
enum.o error.o eval.o file.o gc.o hash.o inits.o io.o marshal.o
math.o numeric.o object.o pack.o parse.o process.o prec.o random.o
range.o re.o regex.o ruby.o signal.o sprintf.o st.o string.o
struct.o time.o util.o variable.o version.o dmyext.o
gcc -g -pipe -rdynamic main.o dmyext.o libruby.a -ldl -lcrypt -lm -o miniruby
gcc -g -pipe -rdynamic -L. main.o -lruby -ldl -lcrypt -lm -o ruby
~/s/ruby-g % ./ruby null.rb
~/s/ruby-g %
とりあえず落ちなくはなったみたいだ。
修正はしたが、他のパターンが動かなくなっていないか、 あるいは落ちないかを確認していない点に不安が残る。 こういうときにテストケースがあれば他の挙動に影響を 与えていないか確かめながら変更できるので非常に楽だ。 そこでまずは挙動が変化していないかを確認するため rubicon にかける。
~/s/ruby-g % cvs -Q -d ~/cvs/ruby co rubicon
~/s/ruby-g % cd rubicon
~/s/ruby-g/rubicon % make # 拡張モジュールがあるので、作っておく
# 出力は略
~/s/ruby-g/rubicon % cd builtin
~/s/ruby-g/rubicon/builtin % ../../ruby TestString.rb
：
：
：
Time: 0.094514
OK (79/79 tests 1213 asserts)
大丈夫らしい。
今度は他のコードで str->ptr == NULL に対処できているかチェックする。 こんなテストはないので地道に書くしかない。リファレンスを見てとりあえず だいたいのパターンを尽くしておく。
def nullstr
' '.dup.rstrip.gsub(/a/, '')
end
nullstr().split(//)
nullstr().split(//, 2)
nullstr().split(//, -1)
nullstr().split(/re/)
nullstr().split(/re/, 2)
nullstr().split(/re/, -1)
nullstr().split('s')
nullstr().split('s', 2)
nullstr().split('s', -1)
nullstr().split('')
nullstr().split('', 2)
nullstr().split('', -1)
nullstr().split
nullstr().split(nullstr())
nullstr().split(nullstr(), 2)
nullstr().split(nullstr(), -1)
こんなとこでパラメタライズするのは時間の無駄。 ひたすらコピペすればよい。 でもってテストする。
~/s/ruby-g % ruby testnull.rb testnull.rb:6: [BUG] Segmentation fault ruby 1.7.3 (2002-09-13) [i686-linux] zsh: 7772 abort (core dumped) ruby testnull.rb ~/s/ruby-g % ./ruby testnull.rb ~/s/ruby-g %
当然ながら、「修正前の ruby がちゃんと落ちるか」もテストしなければならない。 でないとテストにならないからだ。コメントアウトしながら試すと、 最初と最後の三つが落ちるパターンであった。
そんなわけで、原因はわかった。パッチもできた。動作も検証した。 あとはレポートをまとめて ruby-dev に投げれば完了である。