Bug #5768

TestRequire#test_race_exceptionで競合するケースがまだある

Added by Yui NARUSE over 2 years ago. Updated over 1 year ago.

[ruby-dev:45002]
Status:Closed
Priority:Normal
Assignee:Motohiro KOSAKI
Category:core
Target version:2.0.0
ruby -v:- Backport:

Description

まだrequireで競合するケースが残っています。
現在のテストだと確率的にしか起きませんが、以下の通り変更すると確実に起きるようになります。

diff --git a/test/ruby/testrequire.rb b/test/ruby/testrequire.rb
index 9186a6f..262a5ef 100644
--- a/test/ruby/testrequire.rb
+++ b/test/ruby/test
require.rb
@@ -352,7 +352,7 @@ class TestRequire < Test::Unit::TestCase
TestRequire.scratch << :pre
Thread.pass until t2 = TestRequire.scratch[1]
Thread.pass until t2.stop?
-open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"}
+open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"; f.puts "t1,t2=TestRequire.scratch[1, 2];if Thread.current == t2; Thread.pass until t1.stopped?; end"}
raise "con1"
EOS
tmp.close
@@ -364,6 +364,7 @@ raise "con1"
t2_res = nil

 t1 = Thread.new do
  •  scratch << t1
    

    begin
    require(path)
    rescue RuntimeError
    @@ -389,8 +390,8 @@ raise "con1"
    assertnothingraised(ThreadError, bug5754) {t1.join}
    assertnothingraised(ThreadError, bug5754) {t2.join}

  • assertequal(true, (t1res ^ t2_res), bug5754)

  • assert_equal([:pre, t2, :post, :t2, :t1], scratch, bug5754)

  • assertequal(true, (t1res ^ t2res), bug5754 + " t1:#{t1res} t2:#{t2_res}")

  • assert_equal([:pre, t1, t2, :post, :t2, :t1], scratch, bug5754)
    ensure
    tmp.close(true) if tmp
    end


Related issues

Related to ruby-trunk - Bug #5754: Double require bug in 1.9.3 Closed 12/13/2011

Associated revisions

Revision 34163
Added by Yui NARUSE over 2 years ago

  • thread.c (rbbarrierwaiting): save the number of waiting threads
    in RBASIC()->flags. [Bug #5768]

  • thread.c (rbbarrierwait): increment and decrement around
    rbmutexlock, and use rbbarrierwaiting().

  • thread.c (rbbarrierrelease): use rbbarrierwaiting().

  • thread.c (rbbarrierdestroy): ditto.

History

#1 Updated by Tomoyuki Chikanaga over 2 years ago

bug5754 .rb の中で t2 が Thread.current になっているようだったのと、scratch の配列の順序が
違っているようだったので少し変更してみました。

diff --git a/test/ruby/testrequire.rb b/test/ruby/testrequire.rb
index 9186a6f..02f7efe 100644
--- a/test/ruby/testrequire.rb
+++ b/test/ruby/test
require.rb
@@ -349,10 +349,11 @@ class TestRequire < Test::Unit::TestCase
tmp = Tempfile.new(%w"bug5754 .rb")
path = tmp.path
tmp.print <<-EOS
+Thread.pass until TestRequire.scratch[1]
TestRequire.scratch << :pre
-Thread.pass until t2 = TestRequire.scratch[1]
+t2 = TestRequire.scratch[0,2].reject{|t| t == Thread.current}[0]
Thread.pass until t2.stop?
-open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"}
+open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"; f.puts "t1,t2=TestRequire.scratch[0, 2];if Thread.current == t2; Thread.pass until t1.stopped?; end"}
raise "con1"
EOS
tmp.close
@@ -364,6 +365,8 @@ raise "con1"
t2_res = nil

 t1 = Thread.new do
  • Thread.pass until t1
  •  scratch << t1
    

    begin
    require(path)
    rescue RuntimeError
    @@ -376,6 +379,7 @@ raise "con1"
    end

    t2 = Thread.new do

  •  Thread.pass until t2
    

    Thread.pass until scratch[0]
    begin
    scratch << t2
    @@ -389,8 +393,8 @@ raise "con1"
    assertnothingraised(ThreadError, bug5754) {t1.join}
    assertnothingraised(ThreadError, bug5754) {t2.join}

  • assertequal(true, (t1res ^ t2_res), bug5754)

  • assert_equal([:pre, t2, :post, :t2, :t1], scratch, bug5754)

  • assertequal(true, (t1res ^ t2res), bug5754 + " t1:#{t1res} t2:#{t2_res}")

  • assert_equal([t1, t2, :pre, :post, :t2, :t1], scratch, bug5754)
    ensure
    tmp.close(true) if tmp
    end

この状態で testraceexception を実行すると以下のように ThreadError が(require のところで)発生するようになりました。

1) Failure:
testraceexception(TestRequire) [/home/nagachika/opt/ruby-trunk/src/ruby/test/ruby/test_require.rb:386]:
.
Exception raised:
<#>.

とり急ぎご報告まで。

#2 Updated by Yui NARUSE over 2 years ago

追いかけた結果、どうも lock に用いている rbbarrierrelease/rbbarrierdestroy や rbmutexlock のマルチスレッド対応がいまいちだったようです。
前者は rbmutexunlock を外した直後から、待っていた他のスレッドが動き始めるのでもはや mutex->condwaiting は古い情報となってしまう点、
後者は GVL
UNLOCK_BEGIN() した直後から、メインのスレッドが動いてしまう可能性があるのがダメですね。

diff --git a/test/ruby/testrequire.rb b/test/ruby/testrequire.rb
index 9186a6f..f1d8d12 100644
--- a/test/ruby/testrequire.rb
+++ b/test/ruby/test
require.rb
@@ -350,9 +350,18 @@ class TestRequire < Test::Unit::TestCase
path = tmp.path
tmp.print <<-EOS
TestRequire.scratch << :pre
-Thread.pass until t2 = TestRequire.scratch[1]
+TestRequire.scratch << Thread.current
+Thread.pass until t2 = TestRequire.scratch[2]
Thread.pass until t2.stop?
-open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"}
+open(FILE, "w") do |f|
+ f.puts "t1, t2 = TestRequire.scratch[1, 2]"
+ f.puts "if Thread.current == t2"
+ f.puts " TestRequire.scratch << :post"
+ f.puts " until t1.stop?"
+ f.puts " Thread.pass"
+ f.puts " end"
+ f.puts "end"
+end
raise "con1"
EOS
tmp.close
@@ -368,7 +377,6 @@ raise "con1"
require(path)
rescue RuntimeError

end

   t1_res = require(path)

   Thread.pass until fin

@@ -376,7 +384,7 @@ raise "con1"
end

 t2 = Thread.new do
  • Thread.pass until scratch[0]
  •  Thread.pass until scratch[1]
    

    begin
    scratch << t2
    t2res = require(path)
    @@ -389,8 +397,8 @@ raise "con1"
    assert
    nothingraised(ThreadError, bug5754) {t1.join}
    assert
    nothing_raised(ThreadError, bug5754) {t2.join}

  • assertequal(true, (t1res ^ t2_res), bug5754)

  • assert_equal([:pre, t2, :post, :t2, :t1], scratch, bug5754)

  • assertequal(true, (t1res ^ t2res), bug5754 + " t1:#{t1res} t2:#{t2_res}")

  • assertequal([:pre, t1, t2, :post, :t2, :t1], scratch, bug5754)
    ensure
    tmp.close(true) if tmp
    end
    diff --git a/thread.c b/thread.c
    index ced10c2..c46653b 100644
    --- a/thread.c
    +++ b/thread.c
    @@ -3409,7 +3409,6 @@ lock
    func(rbthreadt *th, rbmutext *mutex, int timeout_ms)
    int interrupted = 0;
    int err = 0;

  • mutex->condwaiting++;
    for (;;) {
    if (!mutex->th) {
    mutex->th = th;
    @@ -3438,7 +3437,6 @@ lock
    func(rbthreadt *th, rbmutext *mutex, int timeout_ms)
    err = 0;
    }
    }

  • mutex->cond_waiting--;

    return interrupted;
    }
    @@ -3493,10 +3491,12 @@ rbmutexlock(VALUE self)
    if (vmlivingthreadnum(th->vm) == th->vm->sleeper) {
    timeout
    ms = 100;
    }

  •   mutex->cond_waiting++;
    GVL_UNLOCK_BEGIN();
    interrupted = lock_func(th, mutex, timeout_ms);
    native_mutex_unlock(&mutex->lock);
    GVL_UNLOCK_END();
    
  •   mutex->cond_waiting--;
    
    reset_unblock_function(th, &oldubf);
    

@@ -3727,9 +3727,11 @@ rbbarrierrelease(VALUE self)
{
VALUE mutex = GetBarrierPtr(self);
rbmutext *m;
- rbmutexunlock(mutex);
+ int waiting;
GetMutexPtr(mutex, m);
- return m->condwaiting > 0 ? Qtrue : Qfalse;
+ waiting = m->cond
waiting;
+ rbmutexunlock(mutex);
+ return waiting > 0 ? Qtrue : Qfalse;
}

/*
@@ -3740,10 +3742,12 @@ rbbarrierdestroy(VALUE self)
{
VALUE mutex = GetBarrierPtr(self);
rbmutext *m;
+ int waiting;
DATAPTR(self) = 0;
- rb
mutexunlock(mutex);
GetMutexPtr(mutex, m);
- return m->cond
waiting > 0 ? Qtrue : Qfalse;
+ waiting = m->condwaiting;
+ rb
mutex_unlock(mutex);
+ return waiting > 0 ? Qtrue : Qfalse;
}

int

#3 Updated by Motohiro KOSAKI over 2 years ago

  • Category set to core
  • Assignee changed from Nobuyoshi Nakada to Motohiro KOSAKI
  • Target version set to 2.0.0

lockfuncやrbmutex_lockを変更するのは反対なので、いったん預かります

#4 Updated by Nobuyoshi Nakada over 2 years ago

  • ruby -v changed from ruby 2.0.0dev (2011-12-16 trunk 34058) [x86_64-freebsd9.0] to -

なかだです。

(11/12/20 13:43), Yui NARUSE wrote:

追いかけた結果、どうも lock に用いている rbbarrierrelease/rbbarrierdestroy や rbmutexlock のマルチスレッド対応がいまいちだったようです。
前者は rbmutexunlock を外した直後から、待っていた他のスレッドが動き始めるのでもはや mutex->condwaiting は古い情報となってしまう点、
後者は GVL
UNLOCK_BEGIN() した直後から、メインのスレッドが動いてしまう可能性があるのがダメですね。

たしかに、rbmutexlockがGVLを先に開放していることを見落としていました。
rbbarrierrelease/rbbarrierdestroyが呼ばれた時点ではmutexがロックさ
れていることが前提ですので、後半のBarrier部分の変更だけで充分な気がしま
す。

diff --git a/test/ruby/testrequire.rb b/test/ruby/testrequire.rb
index 9186a6f..f1d8d12 100644
--- a/test/ruby/testrequire.rb
+++ b/test/ruby/test
require.rb
@@ -350,9 +350,18 @@ class TestRequire < Test::Unit::TestCase
path = tmp.path
tmp.print <<-EOS
TestRequire.scratch << :pre
-Thread.pass until t2 = TestRequire.scratch[1]
+TestRequire.scratch << Thread.current
+Thread.pass until t2 = TestRequire.scratch[2]
Thread.pass until t2.stop?
-open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"}
+open(FILE, "w") do |f|
+ f.puts "t1, t2 = TestRequire.scratch[1, 2]"
+ f.puts "if Thread.current == t2"
+ f.puts " TestRequire.scratch << :post"
+ f.puts " until t1.stop?"
+ f.puts " Thread.pass"
+ f.puts " end"
+ f.puts "end"
+end
raise "con1"

この変更ではt2でロードされることを想定していますが、最初のrequireが例外
で中断したあとにt1,t2のどちらが実際にロードすることになるかは不定のはず
です。

--
--- 僕の前にBugはない。
--- 僕の後ろにBugはできる。
中田 伸悦

#5 Updated by Yui NARUSE over 2 years ago

Nobuyoshi Nakada wrote:

rbbarrierrelease/rbbarrierdestroyが呼ばれた時点ではmutexがロックさ
れていることが前提ですので、後半のBarrier部分の変更だけで充分な気がしま
す。

その前提は成立しません。

このテストにおいて、t1 は t2.stop? == true を待ってから、例外によって require を抜けます。
言い換えると、t2 が rbbarrierwait 内の rbmutexlock 内の nativecondwait に到達するのを待ってから、
例外によって require を例外を抜けたいと思っています。
最低限のラインとしては、mutex->cond_waiting++ されてから抜けないといけません。

さて、t2 における rbmutexlock ですが、
thread.c の 3481行目に th->status = THREADSTOPPEDFOREVER という行があります。
これ以降、Thread#stop?はtrueを返すようになりますが、まだ GVL にとって他のスレッドは動けないので大丈夫です。
そこから10行ほど下ると、GVLUNLOCKBEGIN();という行があります。
ここから他のスレッドが動けるようになります、まだこのスレッドは STOP してないのに。
t1 がこの状況で動くと、例外を投げて require を抜け、loadunlock が呼ばれます。
つまりこの時点で前提は崩れます。
そして rb
barrierrelease を呼び、まだ 0 のままのmutex->condwaiting を見て Qfalse を返すため、
loadingtbl から当該パスは削除されてしまいます。
一方、t1 はそれと平行して lock
funcに入り、やっとmutex->condwaiting++します。
30行ほど下って、native
cond_waitで待ちますが、上記のケースの場合この時にはもう手遅れになっています。

まとめると、GVLUNLOCKBEGINから、mutex->condwaiting++の間に、他のスレッドが動いて、
mutex->cond
waitingを見ると、0のままであり、待ってる人がいないと思うので、
待ち人用の何かを破壊したりすると、待ってた人が発狂する。
具体的には、load.c の loadunlock の rbbarrierdestroy/rbbarrierdestroy と、stdelete あたり、というわけです。

diff --git a/test/ruby/testrequire.rb b/test/ruby/testrequire.rb
index 9186a6f..f1d8d12 100644
--- a/test/ruby/testrequire.rb
+++ b/test/ruby/test
require.rb
@@ -350,9 +350,18 @@ class TestRequire < Test::Unit::TestCase
path = tmp.path
tmp.print <<-EOS
TestRequire.scratch << :pre
-Thread.pass until t2 = TestRequire.scratch[1]
+TestRequire.scratch << Thread.current
+Thread.pass until t2 = TestRequire.scratch[2]
Thread.pass until t2.stop?
-open(FILE, "w") {|f| f.puts "TestRequire.scratch << :post"}
+open(FILE, "w") do |f|
+ f.puts "t1, t2 = TestRequire.scratch[1, 2]"
+ f.puts "if Thread.current == t2"
+ f.puts " TestRequire.scratch << :post"
+ f.puts " until t1.stop?"
+ f.puts " Thread.pass"
+ f.puts " end"
+ f.puts "end"
+end
raise "con1"

この変更ではt2でロードされることを想定していますが、最初のrequireが例外
で中断したあとにt1,t2のどちらが実際にロードすることになるかは不定のはず
です。

あぁ、なるほど。なんで :post が含まれないケースがあるのかなぁと思っていました。

#6 Updated by Yui NARUSE over 2 years ago

とりあえず r34163 で mutex->cond_waiting を用いるのをやめ、RBASIC()->flags に待っているスレッドの数を保存するように変更しました。
これで、問題自体は直ったはずですし、現在まで再現していません。
他の方法で実装し直したいと仰っていたので、小崎さんにアサインされたままにはしておきます。

#7 Updated by Motohiro KOSAKI over 1 year ago

  • Status changed from Assigned to Closed

さすがに時期的に、書き直しはあきらめるべきなので、close

Also available in: Atom PDF