[ruby-dev:48297] [ruby-trunk - Bug #9959] [Open] TracePoint can invoke inconsistent call event with bmethod

[ruby-dev:48297] [ruby-trunk - Bug #9959] [Open] TracePoint can invoke inconsistent call event with bmethod

[ko1]

Issue #9959 has been reported by Koichi Sasada.

----------------------------------------
Bug #9959: TracePoint can invoke inconsistent call event with bmethod
https://bugs.ruby-lang.org/issues/9959

* Author: Koichi Sasada
* Status: Open
* Priority: Normal
* Assignee: Koichi Sasada
* Category: core
* Target version: current: 2.2.0
* ruby -v: 2.2
* Backport: 2.0.0: REQUIRED, 2.1: REQUIRED
----------------------------------------
define_method で定義したメソッド（以降、bmethod）を実行するとき、引数のエラーがあったとき、call イベントのみ発生し、return イベントが発生しない、という問題がありました。

```ruby
  define_method(:method_test_argument_error_on_bmethod){|correct_key: 1|}

  def test_argument_error_on_bmethod
    events = []
    curr_thread = Thread.current
    TracePoint.new(:call, :return){|tp|
      next if curr_thread != Thread.current
      events << [tp.event, tp.method_id]
    }.enable do
      begin
        method_test_argument_error_on_bmethod(wrong_key: 2)
      rescue => e
        # ignore
      end
    end

    assert_equal [], events # should be empty.
  end
```

今だと、次のようになります。

```
TestSetTraceFunc#test_argument_error_on_bmethod [test_settracefunc.rb:1258]:
<[]> expected but was
<[[:call, :method_test_argument_error_on_bmethod]]>.
```

これは、Proc を実行する前に TracePoint(call) を発生するが、
例外で戻ろうとしたときに、まだ Proc が起動しておらず、フレームに情報がないため、
return イベントが発生しないため、起こります。

これを解決するために、bmethod 用の call/return イベントを発生する場所を調整しました。

```diff
Index: vm.c
===================================================================
--- vm.c	(revision 46463)
+++ vm.c	(working copy)
@@ -715,15 +715,17 @@
 		    const rb_block_t *blockptr, const NODE *cref,
 		    VALUE defined_class, int splattable)
 {
-    if (SPECIAL_CONST_P(block->iseq))
+    if (SPECIAL_CONST_P(block->iseq)) {
 	return Qnil;
+    }
     else if (BUILTIN_TYPE(block->iseq) != T_NODE) {
+	VALUE ret;
 	const rb_iseq_t *iseq = block->iseq;
 	const rb_control_frame_t *cfp;
 	int i, opt_pc, arg_size = iseq->arg_size;
-	int type = block_proc_is_lambda(block->proc) ?
-	  VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
-
+	int type = block_proc_is_lambda(block->proc) ? VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
+	const rb_method_entry_t *me = th->passed_bmethod_me;
+	th->passed_bmethod_me = 0;
 	cfp = th->cfp;
 
 	for (i=0; i<argc; i++) {
@@ -733,7 +735,7 @@
 	opt_pc = vm_yield_setup_args(th, iseq, argc, cfp->sp, blockptr,
 				     (type == VM_FRAME_MAGIC_LAMBDA) ? splattable+1 : 0);
 
-	if (th->passed_bmethod_me != 0) {
+	if (me != 0) {
 	    /* bmethod */
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH | VM_FRAME_FLAG_BMETHOD,
 			  self, defined_class,
@@ -740,8 +742,10 @@
 			  VM_ENVVAL_PREV_EP_PTR(block->ep),
 			  iseq->iseq_encoded + opt_pc,
 			  cfp->sp + arg_size, iseq->local_size - arg_size,
-			  th->passed_bmethod_me, iseq->stack_max);
-	    th->passed_bmethod_me = 0;
+			  me, iseq->stack_max);
+
+	    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, me->klass, me->called_id);
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, self, me->called_id, me->klass, Qnil);
 	}
 	else {
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH,
@@ -756,7 +760,15 @@
 	    th->cfp->ep[-1] = (VALUE)cref;
 	}
 
-	return vm_exec(th);
+	ret = vm_exec(th);
+
+	if (me) {
+	    /* bmethod */
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, self, me->called_id, me->klass, ret);
+	    RUBY_DTRACE_METHOD_RETURN_HOOK(th, me->klass, me->called_id);
+	}
+
+	return ret;
     }
     else {
 	return vm_yield_with_cfunc(th, block, self, argc, argv, blockptr);
Index: vm_insnhelper.c
===================================================================
--- vm_insnhelper.c	(revision 46462)
+++ vm_insnhelper.c	(working copy)
@@ -1615,17 +1615,11 @@
     rb_proc_t *proc;
     VALUE val;
 
-    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, ci->me->klass, ci->me->called_id);
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, ci->recv, ci->me->called_id, ci->me->klass, Qnil);
-
     /* control block frame */
     th->passed_bmethod_me = ci->me;
     GetProcPtr(ci->me->def->body.proc, proc);
     val = vm_invoke_proc(th, proc, ci->recv, ci->defined_class, ci->argc, argv, ci->blockptr);
 
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, ci->recv, ci->me->called_id, ci->me->klass, val);
-    RUBY_DTRACE_METHOD_RETURN_HOOK(th, ci->me->klass, ci->me->called_id);
-
     return val;
 }
 
```

これも、2.1, 2.0 で再現します。




-- 
https://bugs.ruby-lang.org/

[ruby-dev:48298] [ruby-trunk - Bug #9959] [Closed] TracePoint can invoke inconsistent call event with bmethod

[ko1]

Issue #9959 has been updated by Koichi Sasada.

Status changed from Open to Closed
% Done changed from 0 to 100

Applied in changeset r46464.

----------
* vm.c (invoke_block_from_c): move call/return event timing for
  bmethod. It can invoke inconsistent call event if this call raises
  argument error.
  [Bug #9959]
* vm_insnhelper.c (vm_call_bmethod_body): ditto.
* test/ruby/test_settracefunc.rb: add a test.

----------------------------------------
Bug #9959: TracePoint can invoke inconsistent call event with bmethod
https://bugs.ruby-lang.org/issues/9959#change-47288

* Author: Koichi Sasada
* Status: Closed
* Priority: Normal
* Assignee: Koichi Sasada
* Category: core
* Target version: current: 2.2.0
* ruby -v: 2.2
* Backport: 2.0.0: REQUIRED, 2.1: REQUIRED
----------------------------------------
define_method で定義したメソッド（以降、bmethod）を実行するとき、引数のエラーがあったとき、call イベントのみ発生し、return イベントが発生しない、という問題がありました。

```ruby
  define_method(:method_test_argument_error_on_bmethod){|correct_key: 1|}

  def test_argument_error_on_bmethod
    events = []
    curr_thread = Thread.current
    TracePoint.new(:call, :return){|tp|
      next if curr_thread != Thread.current
      events << [tp.event, tp.method_id]
    }.enable do
      begin
        method_test_argument_error_on_bmethod(wrong_key: 2)
      rescue => e
        # ignore
      end
    end

    assert_equal [], events # should be empty.
  end
```

今だと、次のようになります。

```
TestSetTraceFunc#test_argument_error_on_bmethod [test_settracefunc.rb:1258]:
<[]> expected but was
<[[:call, :method_test_argument_error_on_bmethod]]>.
```

これは、Proc を実行する前に TracePoint(call) を発生するが、
例外で戻ろうとしたときに、まだ Proc が起動しておらず、フレームに情報がないため、
return イベントが発生しないため、起こります。

これを解決するために、bmethod 用の call/return イベントを発生する場所を調整しました。

```diff
Index: vm.c
===================================================================
--- vm.c	(revision 46463)
+++ vm.c	(working copy)
@@ -715,15 +715,17 @@
 		    const rb_block_t *blockptr, const NODE *cref,
 		    VALUE defined_class, int splattable)
 {
-    if (SPECIAL_CONST_P(block->iseq))
+    if (SPECIAL_CONST_P(block->iseq)) {
 	return Qnil;
+    }
     else if (BUILTIN_TYPE(block->iseq) != T_NODE) {
+	VALUE ret;
 	const rb_iseq_t *iseq = block->iseq;
 	const rb_control_frame_t *cfp;
 	int i, opt_pc, arg_size = iseq->arg_size;
-	int type = block_proc_is_lambda(block->proc) ?
-	  VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
-
+	int type = block_proc_is_lambda(block->proc) ? VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
+	const rb_method_entry_t *me = th->passed_bmethod_me;
+	th->passed_bmethod_me = 0;
 	cfp = th->cfp;
 
 	for (i=0; i<argc; i++) {
@@ -733,7 +735,7 @@
 	opt_pc = vm_yield_setup_args(th, iseq, argc, cfp->sp, blockptr,
 				     (type == VM_FRAME_MAGIC_LAMBDA) ? splattable+1 : 0);
 
-	if (th->passed_bmethod_me != 0) {
+	if (me != 0) {
 	    /* bmethod */
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH | VM_FRAME_FLAG_BMETHOD,
 			  self, defined_class,
@@ -740,8 +742,10 @@
 			  VM_ENVVAL_PREV_EP_PTR(block->ep),
 			  iseq->iseq_encoded + opt_pc,
 			  cfp->sp + arg_size, iseq->local_size - arg_size,
-			  th->passed_bmethod_me, iseq->stack_max);
-	    th->passed_bmethod_me = 0;
+			  me, iseq->stack_max);
+
+	    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, me->klass, me->called_id);
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, self, me->called_id, me->klass, Qnil);
 	}
 	else {
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH,
@@ -756,7 +760,15 @@
 	    th->cfp->ep[-1] = (VALUE)cref;
 	}
 
-	return vm_exec(th);
+	ret = vm_exec(th);
+
+	if (me) {
+	    /* bmethod */
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, self, me->called_id, me->klass, ret);
+	    RUBY_DTRACE_METHOD_RETURN_HOOK(th, me->klass, me->called_id);
+	}
+
+	return ret;
     }
     else {
 	return vm_yield_with_cfunc(th, block, self, argc, argv, blockptr);
Index: vm_insnhelper.c
===================================================================
--- vm_insnhelper.c	(revision 46462)
+++ vm_insnhelper.c	(working copy)
@@ -1615,17 +1615,11 @@
     rb_proc_t *proc;
     VALUE val;
 
-    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, ci->me->klass, ci->me->called_id);
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, ci->recv, ci->me->called_id, ci->me->klass, Qnil);
-
     /* control block frame */
     th->passed_bmethod_me = ci->me;
     GetProcPtr(ci->me->def->body.proc, proc);
     val = vm_invoke_proc(th, proc, ci->recv, ci->defined_class, ci->argc, argv, ci->blockptr);
 
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, ci->recv, ci->me->called_id, ci->me->klass, val);
-    RUBY_DTRACE_METHOD_RETURN_HOOK(th, ci->me->klass, ci->me->called_id);
-
     return val;
 }
 
```

これも、2.1, 2.0 で再現します。




-- 
https://bugs.ruby-lang.org/

[ruby-dev:48455] [ruby-trunk - Bug #9959] TracePoint can invoke inconsistent call event with bmethod

[nagachika00]

Issue #9959 has been updated by Tomoyuki Chikanaga.

Backport changed from 2.0.0: REQUIRED, 2.1: REQUIRED to 2.0.0: REQUIRED, 2.1: DONE

Backported into `ruby_2_1` branch at r47013.

----------------------------------------
Bug #9959: TracePoint can invoke inconsistent call event with bmethod
https://bugs.ruby-lang.org/issues/9959#change-48138

* Author: Koichi Sasada
* Status: Closed
* Priority: Normal
* Assignee: Koichi Sasada
* Category: core
* Target version: current: 2.2.0
* ruby -v: 2.2
* Backport: 2.0.0: REQUIRED, 2.1: DONE
----------------------------------------
define_method で定義したメソッド（以降、bmethod）を実行するとき、引数のエラーがあったとき、call イベントのみ発生し、return イベントが発生しない、という問題がありました。

```ruby
  define_method(:method_test_argument_error_on_bmethod){|correct_key: 1|}

  def test_argument_error_on_bmethod
    events = []
    curr_thread = Thread.current
    TracePoint.new(:call, :return){|tp|
      next if curr_thread != Thread.current
      events << [tp.event, tp.method_id]
    }.enable do
      begin
        method_test_argument_error_on_bmethod(wrong_key: 2)
      rescue => e
        # ignore
      end
    end

    assert_equal [], events # should be empty.
  end
```

今だと、次のようになります。

```
TestSetTraceFunc#test_argument_error_on_bmethod [test_settracefunc.rb:1258]:
<[]> expected but was
<[[:call, :method_test_argument_error_on_bmethod]]>.
```

これは、Proc を実行する前に TracePoint(call) を発生するが、
例外で戻ろうとしたときに、まだ Proc が起動しておらず、フレームに情報がないため、
return イベントが発生しないため、起こります。

これを解決するために、bmethod 用の call/return イベントを発生する場所を調整しました。

```diff
Index: vm.c
===================================================================
--- vm.c	(revision 46463)
+++ vm.c	(working copy)
@@ -715,15 +715,17 @@
 		    const rb_block_t *blockptr, const NODE *cref,
 		    VALUE defined_class, int splattable)
 {
-    if (SPECIAL_CONST_P(block->iseq))
+    if (SPECIAL_CONST_P(block->iseq)) {
 	return Qnil;
+    }
     else if (BUILTIN_TYPE(block->iseq) != T_NODE) {
+	VALUE ret;
 	const rb_iseq_t *iseq = block->iseq;
 	const rb_control_frame_t *cfp;
 	int i, opt_pc, arg_size = iseq->arg_size;
-	int type = block_proc_is_lambda(block->proc) ?
-	  VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
-
+	int type = block_proc_is_lambda(block->proc) ? VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
+	const rb_method_entry_t *me = th->passed_bmethod_me;
+	th->passed_bmethod_me = 0;
 	cfp = th->cfp;
 
 	for (i=0; i<argc; i++) {
@@ -733,7 +735,7 @@
 	opt_pc = vm_yield_setup_args(th, iseq, argc, cfp->sp, blockptr,
 				     (type == VM_FRAME_MAGIC_LAMBDA) ? splattable+1 : 0);
 
-	if (th->passed_bmethod_me != 0) {
+	if (me != 0) {
 	    /* bmethod */
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH | VM_FRAME_FLAG_BMETHOD,
 			  self, defined_class,
@@ -740,8 +742,10 @@
 			  VM_ENVVAL_PREV_EP_PTR(block->ep),
 			  iseq->iseq_encoded + opt_pc,
 			  cfp->sp + arg_size, iseq->local_size - arg_size,
-			  th->passed_bmethod_me, iseq->stack_max);
-	    th->passed_bmethod_me = 0;
+			  me, iseq->stack_max);
+
+	    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, me->klass, me->called_id);
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, self, me->called_id, me->klass, Qnil);
 	}
 	else {
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH,
@@ -756,7 +760,15 @@
 	    th->cfp->ep[-1] = (VALUE)cref;
 	}
 
-	return vm_exec(th);
+	ret = vm_exec(th);
+
+	if (me) {
+	    /* bmethod */
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, self, me->called_id, me->klass, ret);
+	    RUBY_DTRACE_METHOD_RETURN_HOOK(th, me->klass, me->called_id);
+	}
+
+	return ret;
     }
     else {
 	return vm_yield_with_cfunc(th, block, self, argc, argv, blockptr);
Index: vm_insnhelper.c
===================================================================
--- vm_insnhelper.c	(revision 46462)
+++ vm_insnhelper.c	(working copy)
@@ -1615,17 +1615,11 @@
     rb_proc_t *proc;
     VALUE val;
 
-    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, ci->me->klass, ci->me->called_id);
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, ci->recv, ci->me->called_id, ci->me->klass, Qnil);
-
     /* control block frame */
     th->passed_bmethod_me = ci->me;
     GetProcPtr(ci->me->def->body.proc, proc);
     val = vm_invoke_proc(th, proc, ci->recv, ci->defined_class, ci->argc, argv, ci->blockptr);
 
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, ci->recv, ci->me->called_id, ci->me->klass, val);
-    RUBY_DTRACE_METHOD_RETURN_HOOK(th, ci->me->klass, ci->me->called_id);
-
     return val;
 }
 
```

これも、2.1, 2.0 で再現します。




-- 
https://bugs.ruby-lang.org/

[ruby-dev:48506] [ruby-trunk - Bug #9959] [Assigned] TracePoint can invoke inconsistent call event with bmethod

[usa]

Issue #9959 has been updated by Usaku NAKAMURA.

Status changed from Closed to Assigned

2.0.0にはそもそも th->passed_bmethod_me がなくて、現在のtrunkのelse節に相当する部分がないんですけど、どうしたもんでしょうか？

----------------------------------------
Bug #9959: TracePoint can invoke inconsistent call event with bmethod
https://bugs.ruby-lang.org/issues/9959#change-48590

* Author: Koichi Sasada
* Status: Assigned
* Priority: Normal
* Assignee: Koichi Sasada
* Category: core
* Target version: current: 2.2.0
* ruby -v: 2.2
* Backport: 2.0.0: REQUIRED, 2.1: DONE
----------------------------------------
define_method で定義したメソッド（以降、bmethod）を実行するとき、引数のエラーがあったとき、call イベントのみ発生し、return イベントが発生しない、という問題がありました。

```ruby
  define_method(:method_test_argument_error_on_bmethod){|correct_key: 1|}

  def test_argument_error_on_bmethod
    events = []
    curr_thread = Thread.current
    TracePoint.new(:call, :return){|tp|
      next if curr_thread != Thread.current
      events << [tp.event, tp.method_id]
    }.enable do
      begin
        method_test_argument_error_on_bmethod(wrong_key: 2)
      rescue => e
        # ignore
      end
    end

    assert_equal [], events # should be empty.
  end
```

今だと、次のようになります。

```
TestSetTraceFunc#test_argument_error_on_bmethod [test_settracefunc.rb:1258]:
<[]> expected but was
<[[:call, :method_test_argument_error_on_bmethod]]>.
```

これは、Proc を実行する前に TracePoint(call) を発生するが、
例外で戻ろうとしたときに、まだ Proc が起動しておらず、フレームに情報がないため、
return イベントが発生しないため、起こります。

これを解決するために、bmethod 用の call/return イベントを発生する場所を調整しました。

```diff
Index: vm.c
===================================================================
--- vm.c	(revision 46463)
+++ vm.c	(working copy)
@@ -715,15 +715,17 @@
 		    const rb_block_t *blockptr, const NODE *cref,
 		    VALUE defined_class, int splattable)
 {
-    if (SPECIAL_CONST_P(block->iseq))
+    if (SPECIAL_CONST_P(block->iseq)) {
 	return Qnil;
+    }
     else if (BUILTIN_TYPE(block->iseq) != T_NODE) {
+	VALUE ret;
 	const rb_iseq_t *iseq = block->iseq;
 	const rb_control_frame_t *cfp;
 	int i, opt_pc, arg_size = iseq->arg_size;
-	int type = block_proc_is_lambda(block->proc) ?
-	  VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
-
+	int type = block_proc_is_lambda(block->proc) ? VM_FRAME_MAGIC_LAMBDA : VM_FRAME_MAGIC_BLOCK;
+	const rb_method_entry_t *me = th->passed_bmethod_me;
+	th->passed_bmethod_me = 0;
 	cfp = th->cfp;
 
 	for (i=0; i<argc; i++) {
@@ -733,7 +735,7 @@
 	opt_pc = vm_yield_setup_args(th, iseq, argc, cfp->sp, blockptr,
 				     (type == VM_FRAME_MAGIC_LAMBDA) ? splattable+1 : 0);
 
-	if (th->passed_bmethod_me != 0) {
+	if (me != 0) {
 	    /* bmethod */
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH | VM_FRAME_FLAG_BMETHOD,
 			  self, defined_class,
@@ -740,8 +742,10 @@
 			  VM_ENVVAL_PREV_EP_PTR(block->ep),
 			  iseq->iseq_encoded + opt_pc,
 			  cfp->sp + arg_size, iseq->local_size - arg_size,
-			  th->passed_bmethod_me, iseq->stack_max);
-	    th->passed_bmethod_me = 0;
+			  me, iseq->stack_max);
+
+	    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, me->klass, me->called_id);
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, self, me->called_id, me->klass, Qnil);
 	}
 	else {
 	    vm_push_frame(th, iseq, type | VM_FRAME_FLAG_FINISH,
@@ -756,7 +760,15 @@
 	    th->cfp->ep[-1] = (VALUE)cref;
 	}
 
-	return vm_exec(th);
+	ret = vm_exec(th);
+
+	if (me) {
+	    /* bmethod */
+	    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, self, me->called_id, me->klass, ret);
+	    RUBY_DTRACE_METHOD_RETURN_HOOK(th, me->klass, me->called_id);
+	}
+
+	return ret;
     }
     else {
 	return vm_yield_with_cfunc(th, block, self, argc, argv, blockptr);
Index: vm_insnhelper.c
===================================================================
--- vm_insnhelper.c	(revision 46462)
+++ vm_insnhelper.c	(working copy)
@@ -1615,17 +1615,11 @@
     rb_proc_t *proc;
     VALUE val;
 
-    RUBY_DTRACE_METHOD_ENTRY_HOOK(th, ci->me->klass, ci->me->called_id);
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_CALL, ci->recv, ci->me->called_id, ci->me->klass, Qnil);
-
     /* control block frame */
     th->passed_bmethod_me = ci->me;
     GetProcPtr(ci->me->def->body.proc, proc);
     val = vm_invoke_proc(th, proc, ci->recv, ci->defined_class, ci->argc, argv, ci->blockptr);
 
-    EXEC_EVENT_HOOK(th, RUBY_EVENT_RETURN, ci->recv, ci->me->called_id, ci->me->klass, val);
-    RUBY_DTRACE_METHOD_RETURN_HOOK(th, ci->me->klass, ci->me->called_id);
-
     return val;
 }
 
```

これも、2.1, 2.0 で再現します。




-- 
https://bugs.ruby-lang.org/