[ruby-core:109084] [Ruby master Bug#18886] Struct aref and aset don't trigger any tracepoints.

["ioquatix (Samuel Williams)" <noreply@ruby-lang.org>]

Issue #18886 has been updated by ioquatix (Samuel Williams).


Here is my performance comparison:

Firstly, with no changes (should be identical, shows some variance).

```
> make benchmark ITEM=vm_struct COMPARE_RUBY=(which ruby)
/home/samuel/.rubies/ruby-head/bin/ruby --disable=gems -rrubygems -I../benchmark/lib ../benchmark/benchmark-driver/exe/benchmark-driver \
            --executables="compare-ruby::/home/samuel/.rubies/ruby-head/bin/ruby -I.ext/common --disable-gem" \
            --executables="built-ruby::./miniruby -I../lib -I. -I.ext/common  ../tool/runruby.rb --extout=.ext  -- --disable-gems --disable-gem" \
            --output=markdown --output-compare -v $(find ../benchmark -maxdepth 1 -name 'vm_struct' -o -name '*vm_struct*.yml' -o -name '*vm_struct*.rb' | sort) 
compare-ruby: ruby 3.2.0dev (2022-06-29T00:53:14Z master 3051d4bc2a) [x86_64-linux]
built-ruby: ruby 3.2.0dev (2022-06-29T02:51:15Z struct-tracepoints 12e97af1d2) [x86_64-linux]
# Iteration per second (i/s)

|                       |compare-ruby|built-ruby|
|:----------------------|-----------:|---------:|
|vm_struct_big_aref_hi  |    149.515M|  147.470M|
|                       |       1.01x|         -|
|vm_struct_big_aref_lo  |    148.916M|  147.628M|
|                       |       1.01x|         -|
|vm_struct_big_aset     |       7.006|     7.080|
|                       |           -|     1.01x|
|vm_struct_big_href_hi  |     27.652M|   27.382M|
|                       |       1.01x|         -|
|vm_struct_big_href_lo  |     27.547M|   27.725M|
|                       |           -|     1.01x|
|vm_struct_big_hset     |       3.049|     3.094|
|                       |           -|     1.01x|
|vm_struct_small_aref   |    144.031M|  136.167M|
|                       |       1.06x|         -|
|vm_struct_small_aset   |       7.032|     7.063|
|                       |           -|     1.00x|
|vm_struct_small_href   |     30.694M|   30.432M|
|                       |       1.01x|         -|
|vm_struct_small_hset   |     28.590M|   28.083M|
|                       |       1.02x|         -|
```

Now with my PR:

```
> make benchmark ITEM=vm_struct COMPARE_RUBY=(which ruby)
/home/samuel/.rubies/ruby-head/bin/ruby --disable=gems -rrubygems -I../benchmark/lib ../benchmark/benchmark-driver/exe/benchmark-driver \
            --executables="compare-ruby::/home/samuel/.rubies/ruby-head/bin/ruby -I.ext/common --disable-gem" \
            --executables="built-ruby::./miniruby -I../lib -I. -I.ext/common  ../tool/runruby.rb --extout=.ext  -- --disable-gems --disable-gem" \
            --output=markdown --output-compare -v $(find ../benchmark -maxdepth 1 -name 'vm_struct' -o -name '*vm_struct*.yml' -o -name '*vm_struct*.rb' | sort) 
compare-ruby: ruby 3.2.0dev (2022-06-29T00:53:14Z master 3051d4bc2a) [x86_64-linux]
built-ruby: ruby 3.2.0dev (2022-06-29T02:51:15Z struct-tracepoints 12e97af1d2) [x86_64-linux]
# Iteration per second (i/s)

|                       |compare-ruby|built-ruby|
|:----------------------|-----------:|---------:|
|vm_struct_big_aref_hi  |    147.665M|  115.510M|
|                       |       1.28x|         -|
|vm_struct_big_aref_lo  |    146.666M|  116.298M|
|                       |       1.26x|         -|
|vm_struct_big_aset     |       7.098|     6.801|
|                       |       1.04x|         -|
|vm_struct_big_href_hi  |     27.608M|   27.957M|
|                       |           -|     1.01x|
|vm_struct_big_href_lo  |     27.521M|   27.937M|
|                       |           -|     1.02x|
|vm_struct_big_hset     |       3.092|     3.113|
|                       |           -|     1.01x|
|vm_struct_small_aref   |    147.494M|  113.729M|
|                       |       1.30x|         -|
|vm_struct_small_aset   |       6.898|     6.840|
|                       |       1.01x|         -|
|vm_struct_small_href   |     31.004M|   31.547M|
|                       |           -|     1.02x|
|vm_struct_small_hset   |     28.433M|   28.527M|
|                       |           -|     1.00x|
```

With changes suggested by @ko1:

```
> make benchmark ITEM=vm_struct COMPARE_RUBY=(which ruby)
/home/samuel/.rubies/ruby-head/bin/ruby --disable=gems -rrubygems -I../benchmark/lib ../benchmark/benchmark-driver/exe/benchmark-driver \
            --executables="compare-ruby::/home/samuel/.rubies/ruby-head/bin/ruby -I.ext/common --disable-gem" \
            --executables="built-ruby::./miniruby -I../lib -I. -I.ext/common  ../tool/runruby.rb --extout=.ext  -- --disable-gems --disable-gem" \
            --output=markdown --output-compare -v $(find ../benchmark -maxdepth 1 -name 'vm_struct' -o -name '*vm_struct*.yml' -o -name '*vm_struct*.rb' | sort) 
compare-ruby: ruby 3.2.0dev (2022-06-29T00:53:14Z master 3051d4bc2a) [x86_64-linux]
built-ruby: ruby 3.2.0dev (2022-06-29T02:51:15Z struct-tracepoints 12e97af1d2) [x86_64-linux]
# Iteration per second (i/s)

|                       |compare-ruby|built-ruby|
|:----------------------|-----------:|---------:|
|vm_struct_big_aref_hi  |    146.836M|  115.141M|
|                       |       1.28x|         -|
|vm_struct_big_aref_lo  |    147.929M|  115.918M|
|                       |       1.28x|         -|
|vm_struct_big_aset     |       7.079|     6.802|
|                       |       1.04x|         -|
|vm_struct_big_href_hi  |     27.495M|   27.933M|
|                       |           -|     1.02x|
|vm_struct_big_href_lo  |     27.396M|   27.584M|
|                       |           -|     1.01x|
|vm_struct_big_hset     |       3.128|     3.095|
|                       |       1.01x|         -|
|vm_struct_small_aref   |    142.123M|  113.700M|
|                       |       1.25x|         -|
|vm_struct_small_aset   |       6.995|     6.755|
|                       |       1.04x|         -|
|vm_struct_small_href   |     30.561M|   31.424M|
|                       |           -|     1.03x|
|vm_struct_small_hset   |     28.353M|   28.650M|
|                       |           -|     1.01x|
```

It seems like 25-30% performance impact, but this is still a very fast operation. Is there any way we can make this faster? Could we have tracing and non-tracing op-codes which call different functions? e.g. `vm_call_opt_struct_aref` and `vm_call_opt_struct_aref_trace` for example.


----------------------------------------
Bug #18886: Struct aref and aset don't trigger any tracepoints.
https://bugs.ruby-lang.org/issues/18886#change-98229

* Author: ioquatix (Samuel Williams)
* Status: Open
* Priority: Normal
* Assignee: ko1 (Koichi Sasada)
* Backport: 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
Given the following program, `thing.name` and `thing.shape` don't trigger `c_call` trace points (or any trace points actually).

```ruby
pp RUBY_VERSION

trace_point = TracePoint.new(:line, :call, :c_call, :a_call) do |trace|
  puts trace.event

  if trace.event == :call
    # Ruby doesn't always mark call-sites in sub-expressions, so we use this approach to compute a call site and mark it:
    if location = caller_locations(2, 1).first and path = location.path
      puts "> #{path}:#{location.lineno}:#{trace.event}"
    end
  end
  
  if path = trace.path
    puts "= #{path}:#{trace.lineno}:#{trace.event}"
  end
end

trace_point.enable

# This will trigger call trace points
class Thing
  def name
    :cat
  end
  
  def shape
    :square
  end
end
thing = Thing.new

# Thing = Struct.new(:name, :shape)
# thing = Thing.new(:cat, :rectangle)

[
  name: thing.name,
  shape: thing.shape,
]
```

## Current HEAD

```
= ../test.rb:30:line:
= ../test.rb:30:c_call:new
= ../test.rb:30:c_call:inherited
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:const_added
= ../test.rb:31:line:
= ../test.rb:31:c_call:new
= ../test.rb:31:c_call:initialize
= ../test.rb:34:line:
```

## Proposed PR

```
= ../test.rb:30:line:
= ../test.rb:30:c_call:new
= ../test.rb:30:c_call:inherited
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:singleton_method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:method_added
= ../test.rb:30:c_call:const_added
= ../test.rb:31:line:
= ../test.rb:31:c_call:new
= ../test.rb:31:c_call:initialize
= ../test.rb:34:line:
= ../test.rb:34:c_call:name
= ../test.rb:35:c_call:shape
```

The reason is the internal implementation of struct doesn't have trace point instrumentation in `vm_call_opt_struct_aset` or `vm_call_opt_struct_aref`.

Proposed fix: https://github.com/ruby/ruby/pull/6071 but this would need a review, maybe @jeremyevans0 and @ko1 can help.



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