Bug #10470
TracePoint cannot trace attr_accessor/reader/writer method
Description
TracePointを利用してattr_accessor
で定義したメソッドの:c_call
, :c_return
イベントを取得することができません。
class Foo
attr_accessor :hoge
def bar
@bar
end
def initialize(val)
@bar = val
end
end
foo = Foo.new("FOO")
trace = TracePoint.new(:return, :c_return) do |tp|
p [tp.lineno, tp.defined_class, tp.method_id, tp.event, tp.binding, tp.return_value]
end
trace.enable do
foo.bar
foo.hoge = "hoge"
foo.hoge
end
上記のコードを実行した時、attr_accessorで定義したhoge
メソッドのイベントが発生しません。
調査した所、EXEC_EVENT_HOOK
の呼び出し自体が無いようです。
このため、例えばpower_assertを利用した時にアクセサメソッドの戻り値を取得できない等の問題が発生します。
attributeの読み書きを行う処理の中にEXEC_EVENT_HOOK
を呼び出す簡単なパッチを書きましたので、添付します。
Files
Related issues
Updated by nobu (Nobuyoshi Nakada) about 6 years ago
- Description updated (diff)
- Category set to core
- Status changed from Open to Assigned
- Assignee set to ko1 (Koichi Sasada)
- Backport changed from 2.0.0: UNKNOWN, 2.1: UNKNOWN to 2.0.0: REQUIRED, 2.1: REQUIRED
Updated by ko1 (Koichi Sasada) about 6 years ago
遅くなりました。
こちら、性能劣化をいやがって、このような仕様にしているところがあります。
同じようなものに、Fixnum 同士の足し算などがあります。
まつもとさんからは、「出来るようにして欲しい」というリクエストを頂いているので、対応したものだか悩んでいるところです。
どなたか、ご協力頂けないでしょうか。
(1) 性能測定
(2) 何か性能劣化がない形で提供する方法はないか
Updated by joker1007 (Tomohiro Hashidate) about 6 years ago
添付したパッチと同じ様にEXEC_EVENT_HOOKを追加して性能測定をしてみました。
測定にはbenchmark-ipsというgemを使って、100msでの実行命令数を計測しています。
測定に使ったソースコードは以下の通りです。
require 'benchmark/ips'
class Foo
attr_accessor :hoge
def bar
@bar
end
def initialize(val)
@bar = val
end
end
foo = Foo.new("FOO")
trace = TracePoint.new(:return, :c_return) do |tp|
[tp.lineno, tp.defined_class, tp.method_id, tp.event, tp.binding, tp.return_value]
end
Benchmark.ips do |x|
x.report("tracing access") do |time|
trace.enable do
foo.bar
foo.hoge = "hoge#{time}"
foo.hoge
end
end
end
結果¶
トレースを実行している場合としていない場合、EXEC_EVENT_HOOK有の場合と無しの場合の組み合わせで実行しています。
trace.enable, EXEC_EVENT_HOOK無し¶
Calculating ------------------------------------- tracing access 25.401k i/100ms ------------------------------------------------- tracing access 8.873B (±26.2%) i/s - 25.151B
trace.enable, EXEC_EVENT_HOOK有り¶
Calculating ------------------------------------- tracing access 18.765k i/100ms ------------------------------------------------- tracing access 4.404B (±26.9%) i/s - 12.809B
trace無し, EXEC_EVENT_HOOK無し¶
Calculating ------------------------------------- tracing access 108.694k i/100ms ------------------------------------------------- tracing access 108.487B (±18.8%) i/s - 187.556B
trace無し, EXEC_EVENT_HOOK有り¶
Calculating ------------------------------------- tracing access 104.899k i/100ms ------------------------------------------------- tracing access 104.985B (±18.4%) i/s - 183.617B
トレースを実行している場合は倍程度パフォーマンスに差があります。
トレースをしていない場合にも、2,3%程度性能劣化してる感じです。
Updated by joker1007 (Tomohiro Hashidate) about 6 years ago
すいません。
元のサンプルコードを流用してしまったので、tracepointの性能測定としては余り適切じゃない感じのコードになってたことに気付きました。
trace = TracePoint.new(:return, :c_return) do |tp|
[tp.lineno, tp.defined_class, tp.method_id, tp.event, tp.binding, tp.return_value]
end
をもっとシンプルな形に変えて検証してみた場合、倍もパフォーマンスに違いは出ませんでした。
EXEC_EVENT_HOOKが無い場合はtp.binding
等がそもそも呼ばれていないのでbindingを作る負荷が大分上乗せされてました…。
修正版とその結果を貼っておきます。
これでもEXEC_EVENT_HOOKがある場合は無い場合と比べてアクセサメソッド分のTracePointのインスタンスが生成されるのでその分の負荷が上乗せされることになります。
require 'benchmark/ips'
class Foo
attr_accessor :hoge
def bar
@bar
end
def initialize(val)
@bar = val
end
end
foo = Foo.new("FOO")
trace = TracePoint.new(:return, :c_return) do |tp|
tp
end
Benchmark.ips do |x|
x.report("tracing access") do |time|
trace.enable do
foo.bar
foo.hoge = "hoge#{time}"
foo.hoge
end
end
end
trace.enable EXEC_EVENT_HOOK無し¶
Calculating ------------------------------------- tracing access 59.598k i/100ms ------------------------------------------------- tracing access 47.489B (±36.5%) i/s - 103.366B
trace.enable EXEC_EVENT_HOOK有り¶
Calculating ------------------------------------- tracing access 55.833k i/100ms ------------------------------------------------- tracing access 39.855B (±41.0%) i/s - 87.620B
Updated by ko1 (Koichi Sasada) over 5 years ago
こちら、随分間をあけてしまって申し訳ありません。
気になるのは、
- 「hook を出来ない状態にして(つまり、現状)、disable のまま実行」
- 「hook を出来る状態にして、disable のまま実行」
の比較なのですが(つまり、enable で遅くなるのは、まぁ気にしない)、こちらお願い出来ますでしょうか。
あと、attr だけでいいんかな。
Updated by mame (Yusuke Endoh) about 1 year ago
- Related to Bug #16383: TracePoint does not report calls to attribute reader methods added