Issue #17152 has been updated by S_H_ (Shun Hiraoka).


This behavior is fixed(alredy backported).

ref: https://bugs.ruby-lang.org/issues/17149
ref: https://github.com/ruby/ruby/commit/3fef159f81fad6ffb9af5b60f4c8ec867fdb2391

----------------------------------------
Bug #17152: Missing TracePoint return event for String#unpack
https://bugs.ruby-lang.org/issues/17152#change-87502

* Author: cfis (Charlie Savage)
* Status: Open
* Priority: Normal
* ruby -v: ruby 2.7.1p83 (2020-03-31 revision a0c7c23c9c) [x64-mingw32]
* Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN
----------------------------------------
A user reported an incorrect call graph for profiled code from ruby prof. See https://github.com/ruby-prof/ruby-prof/issues/279.

After investigation, this is a bug in Ruby 2.7.1 (it works in Ruby 2.6.*, not sure about Ruby 2.7.0).

Take this simple code:

```
str = "AABBCC"
profile = RubyProf::Profile.profile do
  5.times do
    str.unpack("c*")
  end
end

```

If you look at fired trace point events (you can do that by setting the environmental variable RUBY_PROF_TRACE=trace.txt before running ruby-prof), you get:

```
60031140:209717.574422 line     #    D:/src/ruby-prof/test/stack_test.rb:10
60031140:209717.574646 c-call   Integer#times    D:/src/ruby-prof/test/stack_test.rb:10
60031140:209717.574683 line     #    D:/src/ruby-prof/test/stack_test.rb:11
60031140:209717.574704 call     String#unpack    <internal:pack>:256
60031140:209717.574721 line     String#unpack    <internal:pack>:257
60031140:209717.574937 line     #    D:/src/ruby-prof/test/stack_test.rb:11
60031140:209717.574959 call     String#unpack    <internal:pack>:256
60031140:209717.574976 line     String#unpack    <internal:pack>:257
60031140:209717.574991 line     #    D:/src/ruby-prof/test/stack_test.rb:11
60031140:209717.575004 call     String#unpack    <internal:pack>:256
60031140:209717.575020 line     String#unpack    <internal:pack>:257
60031140:209717.575034 line     #    D:/src/ruby-prof/test/stack_test.rb:11
60031140:209717.575047 call     String#unpack    <internal:pack>:256
60031140:209717.575060 line     String#unpack    <internal:pack>:257
60031140:209717.575074 line     #    D:/src/ruby-prof/test/stack_test.rb:11
60031140:209717.575086 call     String#unpack    <internal:pack>:256
60031140:209717.575106 line     String#unpack    <internal:pack>:257
60031140:209717.575121 c-return Integer#times    D:/src/ruby-prof/test/stack_test.rb:10
```

Notice the return tracepoints are not fired. If you use some other method, like string.downcase, they are correctly fired. Perhaps something unique about unpack?

---Files--------------------------------
trace.txt (1.31 KB)


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

Unsubscribe: <mailto:ruby-core-request / ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>