Bug #11271
closedTestObjSpace#test_trace_object_allocations_start_stop_clear occasional failure
Description
手元の環境で ruby_2_2 ブランチ上で make test-all TESTS=objspace/test_objspace.rb と test_objspace.rb だけ指定して実施すると、以下のような 1 Failure になります。
1) Failure:
TestObjSpace#test_trace_object_allocations_start_stop_clear [/Users/nagachika/opt/ruby-2.2/src/ruby_2_2/test/objspace/test_objspace.rb:188]:
<nil> expected but was
<"/Users/nagachika/opt/ruby-2.2/src/ruby_2_2/test/lib/test/unit/assertions.rb">.
手元では trunk では再現せず、make test-all を全体で実行した時も発生しません。しかし以下のような理由でこれはたまたま発生してないだけなのではないかと推測します。
ObjectSpace.trace_object_allocations_stop でトレースが停止された後に作られた obj3 が全く関係ない test/lib/test/unit/assertions.rb で確保されたと報告されてしまっているのですが、これは
- ObjectSpace.trace_object_allocations_start でトレースが開始された後に test/lib/test/unit/assertions.rb でオブジェクト A が確保される(traceobj_arg::object_table に記録される)
- ObjectSpace.trace_object_allocations_stop でトレースが停止される
- オブジェクトA が GC で回収される。既にトレースが停止されているので freeobj_i() は実行されず traceobj_arg::object_table のエントリは残ったまま
- オブジェクトA と同じ struct RVALUE に obj3 が確保される
ということが起きているのではないかと想像して、2. と 3. の順序が入れ変わることを期待して以下のように ObjectSpace.trace_object_allocations_stop の前に GC.start を挿入してみると、発生しなくなりました。
--- a/test/objspace/test_objspace.rb
+++ b/test/objspace/test_objspace.rb
@@ -187,6 +187,7 @@ class TestObjSpace < Test::Unit::TestCase
obj2 = Object.new
end
ensure
+ GC.start
ObjectSpace.trace_object_allocations_stop
obj3 = Object.new
end
そもそも ObjectSpace.trace_object_allocations_start と ObjectSpace.trace_object_allocations_stop で収集してる情報はそういうものなのかもしれないですが(オブジェクトが回収されても object_table には残すモードもあるようですし)、テストを修正するか、ObjectSpace.trace_object_allocations_stop で強制的に GC を走らせてこういう現象がおきにくくするのはどうでしょうか。
ruby_2_2 向けですが GC を走らせる方針では以下のようなパッチでも再現しなくなりました。
Index: ext/objspace/object_tracing.c
===================================================================
--- ext/objspace/object_tracing.c (revision 50922)
+++ ext/objspace/object_tracing.c (working copy)
@@ -206,6 +206,7 @@
}
if (arg->running == 0) {
+ rb_gc_start();
rb_tracepoint_disable(arg->newobj_trace);
rb_tracepoint_disable(arg->freeobj_trace);
arg->newobj_trace = 0;
Updated by ko1 (Koichi Sasada) over 9 years ago
私も気づいていたのですが、見ないことにしておりました。
私自身だと、「テスト変えて解決としよう」と思いたいんですが、
それで利用上、問題ないですかね?
Updated by nagachika (Tomoyuki Chikanaga) over 9 years ago
考えてみると GC.disable の場合もあると思うので ObjectSpace.trace_object_allocations_stop で常に GC.start するのもよくないかもしれませんね。テストのほうで修正するというので良いと思います。 あとテストでの対応は GC.start するのでなくて、逆に GC.disable しておいて ObjectSpace.trace_object_allocations_stop 後の GC を抑制するという方法のほうが確実そうですね(未検証)。
Updated by nagachika (Tomoyuki Chikanaga) over 9 years ago
- Status changed from Open to Closed
Applied in changeset r52128.
- test/objspace/test_objspace.rb
(test_trace_object_allocations_start_stop_clear): clear object
allocation table first to get rid of erronous detection for obj3.
[ruby-dev:49095] [Bug #11271]
Updated by nagachika (Tomoyuki Chikanaga) over 9 years ago
遅くなりましたが r52128 でテストを修正しました。
ただ実は推測していた GC のタイミングの問題ではなくて、このテストに入ってきた時点で別のテストメソッドでの ObjectSpace.trace_object_allocations で登録された情報が残っていて、それが影響していたようで、GC.disable しただけではエラーは収まりませんでした。
なので test_trace_object_allocations_start_stop_clear の先頭で ObjectSpace.trace_object_allocations_clear で object_table をクリアしておくという修正にしました。いちおう [ruby-dev:49095] で書いたようなシナリオもありえるかと思って GC.disable/GC.enable も追加しています。
Updated by nagachika (Tomoyuki Chikanaga) over 9 years ago
- Backport changed from 2.0.0: DONTNEED, 2.1: DONTNEED, 2.2: REQUIRED to 2.0.0: DONTNEED, 2.1: DONTNEED, 2.2: DONE
Backported into ruby_2_2
branch at r52769.