Ruby-1.8 $B$G(B SEGV

日本コントロールシステム(æ ª)の近永と申します。
よろしくおねがいします。

Ruby で社内サーバアプリケーションを作成し運用していたのですが、
先日 glibc が 重複した free() の呼び出しを検出した旨のメッセージと
バックトレース、メモリマップ等が表示されました。
何度か試していると、以下のメッセージを出す時もありました。
[BUG] Segmentation fault
ruby 1.8.5 (2006-08-25) [i686-linux]

この時は Fedora Core のパッケージに含まれていた 1.8.5(2006-08-25)を
使用していたので、先週公開された 1.8.6-preview1 をビルドして、
同じアプリケーションを valgrind 経由で起動してみたところ、
2重 の free() 呼び出しを検出したらしきメッセージを得ました。
少し長いですが念のため valgrind のログ全部を添付します。
最後の「Address 0x4E0FF40 is 0 bytes inside a block of size 32 free’d」
のところがそうだと思うのですが。

再現させるスクリプトですが、この現象が起きるのが起動させて
まる一日後に落ちる(ことがある)という程度のもので、なかなか小さな
スクリプトにすることができていません。
これから探索していくつもりですがかなり時間がかかると思い、
ã¾ãšå ±å‘Šã•ã›ã¦é ‚ãã¾ã—ãŸã€‚

ä»–ã«å¿…è¦ãªæƒ…å ±ã‚„è§£æ±ºã®ãŸã‚ã«ã‚„ã£ã¦ã¿ãŸã‚‰ã„ã„ã“ã¨ãŒã‚ã‚Šã¾ã—ãŸã‚‰
教えていただけたら幸いです。

環境
Fedora Core release 6 (Zod)
Kernel 2.6.18-1.2849.fc6

$ ruby -v
ruby 1.8.6 (2007-02-17 patchlevel 0) [i686-linux]

$ gcc -v
Using built-in specs.
Target: i386-redhat-linux
Configured with: …/configure --prefix=/usr --mandir=/usr/share/man
–infodir=/usr/share/info --enable-shared --enable-threads=posix
–enable-checking=release --with-system-zlib --enable-__cxa_atexit
–disable-libunwind-exceptions --enable-libgcj-multifile
–enable-languages=c,c++,objc,obj-c++,java,fortran,ada
–enable-java-awt=gtk --disable-dssi --enable-plugin
–with-java-home=/usr/lib/jvm/java-1.4.2-gcj-1.4.2.0/jre
–with-cpu=generic --host=i386-redhat-linux
Thread model: posix
gcc version 4.1.1 20061011 (Red Hat 4.1.1-30)

使用している拡張ライブラリ
etc.so
socket.so
cparse.so
fcntl.so

e$BF|K%3%s%H%m!<%k%7%9%F%`e(B(e$B3te(B)e$B$N6a1J$H?=$7$^$9!#e(B
e$B$h$m$7$/$*$M$,$$$7$^$9!#e(B

[ruby-dev:30404] e$B$N7o$NB3Js$G$9!#e(B
e$B$^$@;W$&$h$&$K:F8=$5$;$i$l$:;M6lH,6l$7$F$$$^$9$,!“e(Bstruct SCOPE
e$B$N$”$?$j$,e(B
e$B2x$7$$$H9M$($Fe(B eval.c
e$B$rFI$s$G$$$F$9$3$7$R$C$+$+$k$H$3$m$rH/8+$7$^$7$?!#e(B

proc_invoke e$B$G%9%3!<%W$N%3%T!<$r$7$F$$$k=j$G!“e(Bflags
e$B$r%3%T!<$7$F$$$J$$E@$,e(B
e$B5$$K$J$j$^$7$?!#e(B
e$BA4BN$rGD0.$7$F$$$J$$$N$G!“e(B0e$B%/%j%”$N$^$^$G$$$$$N$+!”%3%T!<$9$Y$-$+e(B
e$B$O$C$-$jJ,$i$J$$$N$G$9$,!"e(BSCOPE_DONT_RECYCLE
e$BEy$,>C$($F$7$^$&$He(B
e$B$h$/$J$$$h$&$J5$$,$7$^$9!#e(B
e$B$I$&$G$7$g$&$+!#e(B

e$BE*30$l$J;XE&$G$7$?$i?=$7Lu$"$j$^$;$s!#e(B

e$B$b$7$3$3$@$C$?$i!“FC0[%/%i%9$KBP$9$ke(B module_eval
e$BFb$G%V%m%C%/EO$7$Ne(B
define_method e$B$r;H$C$F$$$k$H$3$m$,$”$k$N$G!"$=$3$,LdBj$J$N$@$m$&$He(B
e$B?dB,$7$F$3$l$+$i:F8=%9%/%j%W%H$rC5:w$7$F$_$h$&$H;W$$$^$9$,!"<h$j5^$.e(B
e$BJs9p$5$;$FD:$-$^$7$?!#e(B

— eval.c.orig 2007-02-19 18:28:43.000000000 +0900
+++ eval.c 2007-02-26 17:28:49.000000000 +0900
@@ -8547,11 +8547,12 @@
if (klass) _block.frame.last_class = klass;
_block.frame.argc = RARRAY(tmp)->len;
_block.frame.flags = ruby_frame->flags;

  • if (_block.frame.argc && (ruby_frame->flags & FRAME_DMETH)) {
  • if (_block.frame.argc && DMETHOD_P()) {
    NEWOBJ(scope, struct SCOPE);
    OBJSETUP(scope, tmp, T_SCOPE);
    scope->local_tbl = _block.scope->local_tbl;
    scope->local_vars = _block.scope->local_vars;
  •    scope->flags = _block.scope->flags;
       _block.scope = scope;
    
    }
    /* modify current frame */

e$BF|K%3%s%H%m!<%k%7%9%F%`e(B(e$B3te(B)e$B$N6a1J$H?=$7$^$9!#e(B
e$B$h$m$7$/$*$M$,$$$7$^$9!#e(B

e$B=q$-K:$l$F$$$^$7$?$,!"e(B[ruby-dev:30433]e$B$N:9J,$Oe(B
1.8.6-preview2 e$B$Ke(B
e$BBP$9$k$b$N$G$9!#e(B

e$B$=$l$G!";n$7$Ke(B eval.c
e$B$r=$@5$7$?%P!<%8%g%s$GAv$i$;$F$$$?$N$G$9$,!“e(B
e$B$I$&$b8+Ev30$l$@$C$?$h$&$G!”$^$?e(B
*** glibc detected *** : double free or corruption (fasttop): 0x09fc9108


e$B$H$$$&%a%C%;!<%8$r=P$7$F$7$^$$$^$7$?!#e(B

e$B$=$l$Ke(B make test-all e$B$Ge(B
e$B%3%“%@%s%W$7$F$7$^$C$?$N$G!”$I$&$d$i$+$($C$Fe(B
e$B%P%0$rF~$l$F$7$^$C$?$_$?$$$G$9!#e(B
e$B$d$C$Q$jE*30$l$@$C$?$h$&$G$9!#e(B
e$B3NG’ITB-$N$^$^Ej9F$7$F$7$^$$?=$7Lu$"$j$^$;$s$G$7$?!#e(B

e$B:rF|$N=$@5$O:9$7La$7$F0z$-B3$-D4::$7$F$$$-$^$9!#e(B


e$BF|K%3%s%H%m!<%k%7%9%F%`e(B(e$B3te(B)
e$B6a1Je(B e$BCRG7e(B [email protected]

On Mon, 26 Feb 2007 18:12:48 +0900

e$BF|K%3%s%H%m!<%k%7%9%F%`e(B(e$B3te(B)e$B$N6a1J$H?=$7$^$9!#e(B
e$B$h$m$7$/$*$M$,$$$7$^$9!#e(B

e$B$h$&$d$/:F8=$5$;$k%9%/%j%W%H$r:n$l$^$7$?!#e(B
e$B>/$J$/$H$b<j85$N4D6-$G$O3N<B$K:F8=$G$-$F$$$k$h$&$G$9!#e(B
e$B860x$bGD0.$G$-$?$H;W$$$^$9!#e(B

e$B$?$@$7:F8=$5$;$k$3$H$,$G$-$k$N$O!Ve(Bfree()e$B$7$?%a%b%jFbMF$r;2>H$9$k!W$3$H$^$G$G!"e(B
2e$B=Ee(B free()
e$B$,5/$-$k$+$I$&$+$O!“e(Bfree()e$B$7$?%a%b%j$r;2>H$7$?7k2L$K0MB8$7$F$$$k0Ye(B
e$B3N<B$K%”%!<%H$5$;$k$3$H$O$G$-$^$;$s!#e(B

e$B0J2<%l%]!<%H$G$9!#e(B

e$B$^$::F8=$5$;$k%9%/%j%W%H$rE=$j$^$9!#e(B

=========== e$B:F8=%9%/%j%W%He(B(duplicate_free.rb) ===========
require “thread”

(A) for tuning sweep order.

$gcflag = false
def gc_once
unless $gcflag
GC.start
$gcflag = true
end
end

def m1
q = Queue.new
dummy = Array.new(100) do [] end
(class << q; self; end).module_eval do
define_method(:push) do |item|
puts “push(#{item.inspect})”
super(item)
end
end
dummy = nil
gc_once
m2(q)
end

def m2(q)
thr = Thread.new do
2.times do
q.push :tok
sleep 0.1
end
end
q.pop
q.pop
thr.join
nil
end

call twice for sweep original SCOPE…

m1()
m1()
GC.start
=========== duplicate_free.rb e$B$3$3$^$Ge(B ===========

valgrind e$B$G5/F0$9$k$H!"e(Bfree()
e$B$7$?%a%b%j$rFI$b$&$H$7$F$$$k$3$H$,3NG’$G$-$^$9!#e(B
e$B>/$7%9%/%j%W%H$rJQ$($?$@$1$G5/$-$J$+$C$?$j$9$k$N$G!"e(B
e$BB>$N4D6-$G$b:F8=$9$k$+IT0B$G$9$,e(B…

$ valgrind ruby-1.8.6-preview2 duplicate_free.rb
--------------- snip -----------------
==17496== Invalid read of size 4
==17496== at 0x8073D1B: obj_free (gc.c:1256)
==17496== by 0x80736F0: gc_sweep (gc.c:1085)
==17496== by 0x8073FBF: garbage_collect (gc.c:1416)
==17496== by 0x8073FCC: rb_gc (gc.c:1422)
==17496== by 0x8073FDE: rb_gc_start (gc.c:1439)
==17496== by 0x805F5D6: call_cfunc (eval.c:5653)
==17496== by 0x805EB2A: rb_call0 (eval.c:5806)
==17496== by 0x80600DC: rb_call (eval.c:6053)
==17496== by 0x8058F1B: rb_eval (eval.c:3438)
==17496== by 0x80543CA: eval_node (eval.c:1423)
==17496== by 0x805491F: ruby_exec_internal (eval.c:1599)
==17496== by 0x8054963: ruby_exec (eval.c:1619)
==17496== Address 0x40D9FC0 is 0 bytes inside a block of size 20 free’d
==17496== at 0x400501A: free (vg_replace_malloc.c:233)
==17496== by 0x8073D72: obj_free (gc.c:1259)
==17496== by 0x80736F0: gc_sweep (gc.c:1085)
==17496== by 0x8073FBF: garbage_collect (gc.c:1416)
==17496== by 0x8073FCC: rb_gc (gc.c:1422)
==17496== by 0x8073FDE: rb_gc_start (gc.c:1439)
==17496== by 0x805F5D6: call_cfunc (eval.c:5653)
==17496== by 0x805EB2A: rb_call0 (eval.c:5806)
==17496== by 0x80600DC: rb_call (eval.c:6053)
==17496== by 0x8058F1B: rb_eval (eval.c:3438)
==17496== by 0x80543CA: eval_node (eval.c:1423)
==17496== by 0x805491F: ruby_exec_internal (eval.c:1599)

e$B$3$l$,H/@8$9$k>r7o$O$+$J$j9~$_$$$C$F$^$7$Fe(B

  1. define_method e$B$G%a%=%C%I$rDj5Ae(B

e$B$GDj5A$7$?%a%=%C%I$r8F$S=P$7Cf$K!"%9%l%C%I$N%3%s%F%-%9%H%9%$%C%AH/@8e(B
3) 1) e$B$NDj5A;~$Ne(B struct SCOPE
e$B$H!"e(B2)e$B$G%a%=%C%I8F$S=P$7$7$?;~$K!“e(B
eval.c:8551(1.8.6-preview2) e$B$”$?$j$G@8@.$5$l$ke(B struct SCOPE
e$B$,F1;~$Ke(B
GC e$BBP>]$H$J$k!#e(B
4) e$B$7$+$b%*%j%8%J%k$NJ}$Ne(B struct SCOPE e$B$,@h$Ke(B obj_free()
e$B$,8F$P$l$k!#e(B

e$B$H$$$&$H$3$m$@$H;W$$$^$9!#e(B
e$B:F8=%9%/%j%W%H$Ne(B gc_once e$B$NB8:_$H$+!"e(Bm1
e$B$re(B2e$BEY8F$s$G$$$k$N$O!"e(B3),4) e$B$N>r7o$re(B
e$BK~$?$9$?$aI,MW$J$h$&$@$C$?$+$i$G$9!#e(B

e$B%3%T!<$5$l$?e(B struct SCOPE e$B$Ne(B flags e$B$,e(B 2) e$B$K$h$je(B
SCOPE_DONT_RECYCLE(4)e$B$,e(B
e$BIU$1$i$l$?8e$Ge(B scope_dup() e$B$5$l$J$$$^$^e(B obj_free()
e$B$KMh$k$H!“e(B
e$B%%j%8%J%k$HF1$8e(B local_vars[-1] e$B$r8+$F$7$^$$$^$9!#e(B
e$BF1$82s$Ne(B GC e$B$G%
%j%8%J%k$Ne(B SCOPE e$B$be(B GC
e$BBP>]$G!”$+$D@h$Ke(B sweep e$B$5$l$Fe(B
e$B$$$?>l9g!"4{$K$=$NNN0h$Oe(B free() e$B$5$l$F$7$^$C$F$$$^$9!#e(B

e$B$5$i$K$3$3$Ge(B free() e$B$5$l$?%a%b%jNN0h$N@hF,e(B4e$B%P%$%H$,e(B 0
e$B$K$J$C$Fe(B
e$B$$$k;~$K$+$.$j!"e(Blocal_tbl(e$B$3$l$b%*%j%8%J%k$Ne(B SCOPE e$B$Ne(B
sweep e$B;~$Ke(B free()e$B:Q$_e(B)e$B$re(B
free() e$B$7$F$7$^$C$Fe(B 2e$B=Ee(B free() e$B$H$J$j$^$9!#e(B

e$B0l1~@[:n$N%Q%C%A$bE=$j$^$9!#e(B
valgrind e$B$N<B9T$G!Ve(BAddress *** is 0 bytes inside a block of size
20 free’de$B!We(B
e$B$N%a%C%;!<%8$,=P$J$/$J$k$3$H$H!"e(Bmake check
e$B$,DL$k$3$@$1$O3NG’CW$7$^$7$?!#e(B

e$B$b$&$9$0e(B 1.8.6
e$B$,%j%j!<%9$5$l$k$3$H$H;W$$$^$9$,!"$G$-$l$P$3$N7o$X$NBP:v$be(B
e$BF~$C$F$$$?$i4r$7$$$G$9!#e(B
e$B$H$$$&$N$b!":#2s$N%5!<%P$O>-Mh$*5R$5$s$K$bDs6!$9$k$+$b$7$l$:!"e(B
e$B5R@h4D6-$G$O$?$$$F$$3F<o%G%#%9%H%j%S%e!<%7%g%s$N%Q%C%1!<%8$re(B
e$B;H$&$3$H$K$J$k$H;W$$$^$9$N$G!“e(Bruby-1.8.6 e$B0J9_!”$H$$$&$h$&$Je(B
e$B;XDj$,$G$-$k$[$&$,3Z$G$9$N$G!#e(B

e$B$h$m$7$/$48!F$$/$@$5$$!#e(B

e$B0J2<e(B ruby-1.8.6-preview2 e$B$KBP$9$k%Q%C%A$G$9!#e(B

— src/ruby-1.8.6-preview2/env.h 2007-02-13 08:01:19.000000000
+0900
+++ src/ruby-1.8.6-preview2-modify/env.h 2007-03-01
11:19:50.000000000 +0900
@@ -43,6 +43,7 @@
#define SCOPE_MALLOC 1
#define SCOPE_NOSTACK 2
#define SCOPE_DONT_RECYCLE 4
+#define SCOPE_CLONE 8

extern int ruby_in_eval;

— src/ruby-1.8.6-preview2/parse.y 2007-02-20 15:53:16.000000000
+0900
+++ src/ruby-1.8.6-preview2-modify/parse.y 2007-03-01
11:26:35.000000000 +0900
@@ -5725,7 +5725,8 @@
rb_mem_clear(ruby_scope->local_vars+i, len-i);
}
if (ruby_scope->local_tbl && ruby_scope->local_vars[-1] ==
0) {

  •           xfree(ruby_scope->local_tbl);
    
  •           if (!(ruby_scope->flags & SCOPE_CLONE))
    
  •               xfree(ruby_scope->local_tbl);
          }
          ruby_scope->local_tbl = local_tbl();
      }
    

— src/ruby-1.8.6-preview2/eval.c 2007-02-19 18:28:43.000000000
+0900
+++ src/ruby-1.8.6-preview2-modify/eval.c 2007-03-01
10:39:08.000000000 +0900
@@ -8547,11 +8547,12 @@
if (klass) _block.frame.last_class = klass;
_block.frame.argc = RARRAY(tmp)->len;
_block.frame.flags = ruby_frame->flags;

  • if (_block.frame.argc && (ruby_frame->flags & FRAME_DMETH)) {
  • if (_block.frame.argc && DMETHOD_P()) {
    NEWOBJ(scope, struct SCOPE);
    OBJSETUP(scope, tmp, T_SCOPE);
    scope->local_tbl = _block.scope->local_tbl;
    scope->local_vars = _block.scope->local_vars;
  •   scope->flags |= SCOPE_CLONE;
       _block.scope = scope;
    
    }
    /* modify current frame */

— src/ruby-1.8.6-preview2/gc.c 2007-02-13 08:01:19.000000000
+0900
+++ src/ruby-1.8.6-preview2-modify/gc.c 2007-03-01 11:23:48.000000000
+0900
@@ -1253,7 +1253,7 @@
if (RANY(obj)->as.scope.local_vars &&
RANY(obj)->as.scope.flags != SCOPE_ALLOCA) {
VALUE *vars = RANY(obj)->as.scope.local_vars-1;

  •       if (vars[0] == 0)
    
  •       if (!(RANY(obj)->as.scope.flags & SCOPE_CLONE) && vars[0] == 
    
  1.          RUBY_CRITICAL(free(RANY(obj)->as.scope.local_tbl));
         if (RANY(obj)->as.scope.flags & SCOPE_MALLOC)
             RUBY_CRITICAL(free(vars));

At Fri, 2 Mar 2007 19:08:48 +0900,
I wrote:

問題ないように思います。

 ほかの方々にもレビューをお願いしたいのですが、どうでしょうか。

 ruby_1_8 および ruby_1_8_6 に入れました。


/
/__ __ Akinori.org / MUSHA.org
/ ) ) ) ) / FreeBSD.org / Ruby-lang.org
Akinori MUSHA aka / (_ / ( (__( @ iDaemons.org / and.or.jp

“Different eyes see different things,
Different hearts beat on different strings –
But there are times for you and me when all such things agree”

At Thu, 1 Mar 2007 12:07:40 +0900,
Chikanaga Tomoyuki wrote:

ようやく再現させるスクリプトを作れました。
少なくとも手元の環境では確実に再現できているようです。
åŽŸå› ã‚‚æŠŠæ¡ã§ããŸã¨æ€ã„ã¾ã™ã€‚

 厄介な調査をありがとうございます。

 残念ながら、手元の FreeBSD, OS X, Linux 環境のいずれでも再現は
ã§ãã¾ã›ã‚“ã§ã—ãŸãŒã€ä»°ã‚‹çµæžœãŒãã®é€šã‚Šã ã¨ã™ã‚‹ã¨ã€é ‚ã„ãŸãƒ‘ãƒƒãƒã§
問題ないように思います。

 ほかの方々にもレビューをお願いしたいのですが、どうでしょうか。

もうすぐ 1.8.6 がリリースされることと思いますが、できればこの件への対策も
入っていたら嬉しいです。

 本件以外にも解決したい問題が残っているため、 1.8.6 リリースは
延期することにしました。追って正式にアナウンスします。


/
/__ __ Akinori.org / MUSHA.org
/ ) ) ) ) / FreeBSD.org / Ruby-lang.org
Akinori MUSHA aka / (_ / ( (__( @ iDaemons.org / and.or.jp

“Different eyes see different things,
Different hearts beat on different strings –
But there are times for you and me when all such things agree”