From: Takahiro Kambe <taca@...>
Date: 2010-01-08T12:43:41+09:00
Subject: [ruby-dev:39988] Re: [ruby-list:46704] [ANN] Ruby 1.8.7-p248 released.

こんにちは。

昨年暮れにリリースされた Ruby 1.8.7-p248 ですが、その前の p174 に比べ
て不可思議な現象を確認しています。

環境:	NetBSD 5.0_STABLEおよびcurrent (5.99.22) / i386

make test-all を実行したときに、threadのテストで先に進まなくなります。
調べてわかったことは、以下のようになります。

o test/thread/test_thread.rbから実行されるlbtest.rbを直接実行すると、
  問題なく完了する。

o test/thread/test_thread.rbの test_local_barrier メソッド内で、
  lbtest.rbの呼び出しをを10回繰り返しているが、

  * これを1回にすると問題なく完了する。
  * 2回以上繰り返すと2回目から、

            result = `#{EnvUtil.rubybin} #{lbtest}`

    の結果を待ち続けてブロックした状態になる。

  * この状態で、Control-Cで中断すると、lbtest.rbを実行しているRubyの
    プロセスが残って、SIGKILL以外のシグナルを無視しているようだ。

以下の方法で確認しています。

% eval "`make -n test-all` -v thread"		(threadだけ実行)
Loaded suite thread
Started
test_condvar(TC_Thread): .
test_condvar_wait_exception_handling(TC_Thread): .
test_condvar_wait_not_owner(TC_Thread): .
test_local_barrier(TC_Thread): ^C./test/thread/test_thread.rb:75:in ``': Interrupt
        from ./test/thread/test_thread.rb:75:in `test_local_barrier'
        from ./test/thread/test_thread.rb:74:in `times'
        from ./test/thread/test_thread.rb:74:in `test_local_barrier'
(以下省略)
% ps jc |egrep ruby
taca  4116     1   546 d326a8    0 Il   ttyp2 0:00.10 ruby18
% kill 4116
% ps jc |egrep ruby
taca  4116     1   546 d326a8    0 Sl   ttyp2 0:00.16 ruby18
% gcore 4116
% gdb ruby18 ruby18.core
(省略)
Core was generated by `ruby18'.
#0  0xbba31017 in ___lwp_park50 () from /usr/lib/libc.so.12
(gdb) where
#0  0xbba31017 in ___lwp_park50 () from /usr/lib/libc.so.12
#1  0xbbb0db43 in pthread_cond_timedwait () from /usr/lib/libpthread.so.1
#2  0xbbb3d6e0 in thread_timer ()
   from /data/work/lang/ruby18-base/work.edge/ruby-1.8.7-p248/libruby18.so.18
#3  0xbbb0ff1b in pthread_create () from /usr/lib/libpthread.so.1
#4  0xbba31030 in ___lwp_park50 () from /usr/lib/libc.so.12
#5  0xbb600000 in ?? ()
#6  0x08049ad0 in ?? ()
#7  0xbb500000 in ?? ()
#8  0x00000000 in ?? ()

改めてlbtest.rbを呼び出している側、test/thread/test_thread.rbを実行中
のRubyのプロセスをgcore(1)を使って状態を見ると、

(gdb) where
#0  0xbb9ef4c7 in read () from /usr/lib/libc.so.12
#1  0xbbb0ada8 in read () from /usr/lib/libpthread.so.1
#2  0xbbab0f82 in __sread () from /usr/lib/libc.so.12
#3  0xbbaa4dbf in __srefill () from /usr/lib/libc.so.12
#4  0xbbaa4cd3 in __srget () from /usr/lib/libc.so.12
#5  0xbbaa4649 in getc () from /usr/lib/libc.so.12
#6  0xbbb60094 in io_fread ()
   from /data/work/lang/ruby18-base/work.edge/ruby-1.8.7-p248/libruby18.so.18
#7  0xbbb60246 in read_all ()
   from /data/work/lang/ruby18-base/work.edge/ruby-1.8.7-p248/libruby18.so.18
#8  0xbbb65051 in rb_f_backquote ()
   from /data/work/lang/ruby18-base/work.edge/ruby-1.8.7-p248/libruby18.so.18
...

と、readでブロックしていることが確認できます。

以上、状況の調査だけで解決方法は不明です。

-- 
神戸 隆博(かんべ たかひろ)		at 仕事場