[ruby-trunk - Bug #7032][Open] TestSetTraceFuncの実行に失敗する

Ruby Development
1

Issue #7032 has been reported by ktsj (Kazuki Tsujimoto).

Bug #7032: TestSetTraceFuncの実行に失敗する

Author: ktsj (Kazuki Tsujimoto)
Status: Open
Priority: Normal
Assignee:
Category:
Target version:
ruby -v: ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

=begin
辻本です。

以下のようにテストを実行すると、まれにTestSetTraceFuncの実行に失敗することがあります。

$ make TESTS=‘-vq -j1 objspace/test_objspace.rb
json/test_json_fixtures.rb
json/test_json.rb
xmlrpc/test_marshal.rb
xmlrpc/test_features.rb
uri/test_parser.rb
uri/test_http.rb
uri/test_ftp.rb
uri/test_generic.rb
io/console/test_io_console.rb
rexml/test_stream.rb
rexml/test_light.rb
rexml/test_xpathtext.rb
rexml/test_xpath_pred.rb
rexml/test_rexml_issuezilla.rb
ruby/test_case.rb
ruby/test_hash.rb
ruby/test_marshal.rb
ruby/test_proc.rb
ruby/test_yield.rb
ruby/test_string.rb
ruby/test_settracefunc.rb’ test-all

失敗するケースは2つ確認していて、
1つめがRubyレベルで失敗するもの:

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
TestSetTraceFunc#test_call = 0.00 s = .
TestSetTraceFunc#test_class = 0.00 s = .
TestSetTraceFunc#test_invalid_proc = 0.00 s = .
TestSetTraceFunc#test_raise = 0.00 s = .
TestSetTraceFunc#test_raise_in_trace = 0.00 s = .
TestSetTraceFunc#test_remove_in_trace = 0.00 s = .
TestSetTraceFunc#test_return = 0.00 s = .
TestSetTraceFunc#test_return2 = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite': undefined local variable or method local_var’ for
#Test::Unit::Worker:0x002aaaaaf8a5a0 (NameError)
xyzzy:2:in eval' xyzzy:2:in block in trace_by_tracepoint’
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite' /home/k_tsj/work/ruby/lib/test/unit/parallel.rb:36:in block in
_run_suite’

2つめがSEGVを起こすものになります。

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37: [BUG] Segmentation
fault
ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

– Control frame information

c:0002 p:0045 s:0006 b:0005 e:000e40 BLOCK
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37 [FINISH]
c:0001 p:---- s:0002 b:0002 e:000001 TOP [FINISH]

/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37:in `block in
_run_suite’
=end

2

ありがとうございます．
この辺，考えていたんですが，

(1) event_hooks（イベントのリスト）は thread ごとではなく，
VM 1つだけに持たせる
（Thread ごとにフィルタするために，イベントにフィルタを設ける）

(2) event_hooks は thread ごとにもたせ，グローバルなモノは外す
（グローバルなイベントは，全スレッドにコピー）

のどちらかにしようかなぁ，と考えています．

実は，誰も Thread#set_trace_func なんて使っていないような気がするので，
(1) で十分ではないか，と．

実際のところ，どうなんでしょうね？

3

Issue #7032 has been updated by ktsj (Kazuki Tsujimoto).

=begin
SEGVする問題については、すでにトレースが実行されている場合は
clean_hooksしないという形で修正しました。

"undefined local variable or method"となる問題はtrunkで
再現できないのでこのチケットはクローズします。
再発するようであれば新しくチケットを作りたいと思います。
=end

Bug #7032: TestSetTraceFuncの実行に失敗する

Author: ktsj (Kazuki Tsujimoto)
Status: Closed
Priority: Normal
Assignee:
Category:
Target version:
ruby -v: ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

=begin
辻本です。

以下のようにテストを実行すると、まれにTestSetTraceFuncの実行に失敗することがあります。

$ make TESTS=‘-vq -j1 objspace/test_objspace.rb
json/test_json_fixtures.rb
json/test_json.rb
xmlrpc/test_marshal.rb
xmlrpc/test_features.rb
uri/test_parser.rb
uri/test_http.rb
uri/test_ftp.rb
uri/test_generic.rb
io/console/test_io_console.rb
rexml/test_stream.rb
rexml/test_light.rb
rexml/test_xpathtext.rb
rexml/test_xpath_pred.rb
rexml/test_rexml_issuezilla.rb
ruby/test_case.rb
ruby/test_hash.rb
ruby/test_marshal.rb
ruby/test_proc.rb
ruby/test_yield.rb
ruby/test_string.rb
ruby/test_settracefunc.rb’ test-all

失敗するケースは2つ確認していて、
1つめがRubyレベルで失敗するもの:

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
TestSetTraceFunc#test_call = 0.00 s = .
TestSetTraceFunc#test_class = 0.00 s = .
TestSetTraceFunc#test_invalid_proc = 0.00 s = .
TestSetTraceFunc#test_raise = 0.00 s = .
TestSetTraceFunc#test_raise_in_trace = 0.00 s = .
TestSetTraceFunc#test_remove_in_trace = 0.00 s = .
TestSetTraceFunc#test_return = 0.00 s = .
TestSetTraceFunc#test_return2 = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite': undefined local variable or method local_var’ for
#Test::Unit::Worker:0x002aaaaaf8a5a0 (NameError)
xyzzy:2:in eval' xyzzy:2:in block in trace_by_tracepoint’
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite' /home/k_tsj/work/ruby/lib/test/unit/parallel.rb:36:in block in
_run_suite’

2つめがSEGVを起こすものになります。

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37: [BUG] Segmentation
fault
ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

– Control frame information

c:0002 p:0045 s:0006 b:0005 e:000e40 BLOCK
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37 [FINISH]
c:0001 p:---- s:0002 b:0002 e:000001 TOP [FINISH]

/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37:in `block in
_run_suite’
=end

4

Issue #7032 has been updated by ktsj (Kazuki Tsujimoto).

=begin
SEGVの問題について調べてみました。

手元の環境では以下のコードで100%再現します。

Thread(A)

th = Thread.new { loop { 0 } }

Thread(B)

loop do

test_remove_in_trace

func = lambda do |e, f, l, i, b, k|
set_trace_func(nil)
eval(“self”, b) # allocate many objects
end
set_trace_func(func)
end

この際の流れは次のようになっているようです。

(1) Thread(B)でset_trace_func(nil)されhookにRUBY_HOOK_FLAG_DELETEDフラグが立つ
(2)
直後にThread(A)に切り替わると、(Thread(A)のtrace_runningは0のままなので)exec_hooksが実行されてclean_hookされる
(3) hookと同一アドレスに新しいオブジェクトが生成される
(4) Thread(B)に戻るとhookが無効な値になっているため、参照すると落ちる

試しにフラグを立てたスレッドに限って解放処理を行うようにしたところ落ちなくなりました。

diff --git a/vm_trace.c b/vm_trace.c
index 90c2bd2…1393e89 100644
— a/vm_trace.c
+++ b/vm_trace.c
@@ -41,6 +41,7 @@ typedef struct rb_event_hook_struct {
rb_event_flag_t events;
rb_event_hook_func_t func;
VALUE data;

  • rb_thread_id_t deleted_thread_id;
    struct rb_event_hook_struct *next;
    } rb_event_hook_t;

@@ -183,11 +184,13 @@ remove_event_hook(rb_hook_list_t *list,
rb_event_hook_func_t func, VALUE data)
{
int ret = 0;
rb_event_hook_t *hook = list->hooks;

  • rb_thread_t *th = GET_THREAD();

    while (hook) {
    if (func == 0 || hook->func == func) {
    if (data == Qundef || hook->data == data) {
    hook->hook_flags |= RUBY_HOOK_FLAG_DELETED;

  • hook->deleted_thread_id = th->thread_id;
    ret+=1;
    list->need_clean++;
    }
    @@ -250,12 +253,13 @@ static void
    clean_hooks(rb_hook_list_t *list)
    {
    rb_event_hook_t *hook, **nextp = &list->hooks;

  • rb_thread_t *th = GET_THREAD();

    list->events = 0;
    list->need_clean = 0;

    while ((hook = *nextp) != 0) {

  • if (hook->hook_flags & RUBY_HOOK_FLAG_DELETED) {
  • if (hook->hook_flags & RUBY_HOOK_FLAG_DELETED &&
    hook->deleted_thread_id == th->thread_id) {
    *nextp = hook->next;
    recalc_remove_ruby_vm_event_flags(hook->events);
    xfree(hook);
    =end

Bug #7032: TestSetTraceFuncの実行に失敗する

Author: ktsj (Kazuki Tsujimoto)
Status: Open
Priority: Normal
Assignee:
Category:
Target version:
ruby -v: ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

=begin
辻本です。

以下のようにテストを実行すると、まれにTestSetTraceFuncの実行に失敗することがあります。

$ make TESTS=‘-vq -j1 objspace/test_objspace.rb
json/test_json_fixtures.rb
json/test_json.rb
xmlrpc/test_marshal.rb
xmlrpc/test_features.rb
uri/test_parser.rb
uri/test_http.rb
uri/test_ftp.rb
uri/test_generic.rb
io/console/test_io_console.rb
rexml/test_stream.rb
rexml/test_light.rb
rexml/test_xpathtext.rb
rexml/test_xpath_pred.rb
rexml/test_rexml_issuezilla.rb
ruby/test_case.rb
ruby/test_hash.rb
ruby/test_marshal.rb
ruby/test_proc.rb
ruby/test_yield.rb
ruby/test_string.rb
ruby/test_settracefunc.rb’ test-all

失敗するケースは2つ確認していて、
1つめがRubyレベルで失敗するもの:

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
TestSetTraceFunc#test_call = 0.00 s = .
TestSetTraceFunc#test_class = 0.00 s = .
TestSetTraceFunc#test_invalid_proc = 0.00 s = .
TestSetTraceFunc#test_raise = 0.00 s = .
TestSetTraceFunc#test_raise_in_trace = 0.00 s = .
TestSetTraceFunc#test_remove_in_trace = 0.00 s = .
TestSetTraceFunc#test_return = 0.00 s = .
TestSetTraceFunc#test_return2 = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite': undefined local variable or method local_var’ for
#Test::Unit::Worker:0x002aaaaaf8a5a0 (NameError)
xyzzy:2:in eval' xyzzy:2:in block in trace_by_tracepoint’
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:40:in rescue in block in _run_suite' /home/k_tsj/work/ruby/lib/test/unit/parallel.rb:36:in block in
_run_suite’

2つめがSEGVを起こすものになります。

TestSetTraceFunc#test_break = 0.00 s = .
TestSetTraceFunc#test_c_call = 0.00 s = .
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37: [BUG] Segmentation
fault
ruby 2.0.0dev (2012-09-16 trunk 36980) [x86_64-linux]

– Control frame information

c:0002 p:0045 s:0006 b:0005 e:000e40 BLOCK
/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37 [FINISH]
c:0001 p:---- s:0002 b:0002 e:000001 TOP [FINISH]

/home/k_tsj/work/ruby/lib/test/unit/parallel.rb:37:in `block in
_run_suite’
=end