Ruby2.7ではRubyで実装されたメソッドは挙動が以前と違う話

Ruby Issue Tracking System で見つけたチケットのバグを調べたときのあれこれをまとめたものです。

ちなみに、調べたチケットはこれ

bugs.ruby-lang.org

簡単に言うとruby-profでコードの挙動を追うと意図したものと異なっているみたい

挙動が違う箇所

Ruby 2.6 でチケットにあるコードを実行すると以下のようなログがとれます。

require 'ruby-prof'

str = "AABBCC"
profile = RubyProf::Profile.profile do
  5.times do
    str.unpack("c*")
  end
end
21587600:115368.898844 line     #    bug.rb: 5
21587600:115368.898935 c-call   Integer#times    bug.rb: 5
21587600:115368.898946 line     #    bug.rb: 6
21587600:115368.898950 c-call   String#unpack    bug.rb: 6
21587600:115368.898957 c-return String#unpack    bug.rb: 6
21587600:115368.898962 line     #    bug.rb: 6
21587600:115368.898965 c-call   String#unpack    bug.rb: 6
21587600:115368.898969 c-return String#unpack    bug.rb: 6
21587600:115368.898972 line     #    bug.rb: 6
21587600:115368.898975 c-call   String#unpack    bug.rb: 6
21587600:115368.898978 c-return String#unpack    bug.rb: 6
21587600:115368.898981 line     #    bug.rb: 6
21587600:115368.898984 c-call   String#unpack    bug.rb: 6
21587600:115368.898987 c-return String#unpack    bug.rb: 6
21587600:115368.898990 line     #    bug.rb: 6
21587600:115368.898993 c-call   String#unpack    bug.rb: 6
21587600:115368.898996 c-return String#unpack    bug.rb: 6
21587600:115368.898999 c-return Integer#times    bug.rb: 5

Cの関数としてString#unpackが呼び出され、その後c-returnでreturnされています。

しかし、Ruby 2.7では以下のようにログが変わります。

18616920:115460.887200 line     #    bug.rb: 5
18616920:115460.887364 c-call   Integer#times    bug.rb: 5
18616920:115460.887377 line     #    bug.rb: 6
18616920:115460.887383 call     String#unpack    <internal:pack>:256
18616920:115460.887388 line     String#unpack    <internal:pack>:257
18616920:115460.887399 line     #    bug.rb: 6
18616920:115460.887403 call     String#unpack    <internal:pack>:256
18616920:115460.887406 line     String#unpack    <internal:pack>:257
18616920:115460.887410 line     #    bug.rb: 6
18616920:115460.887413 call     String#unpack    <internal:pack>:256
18616920:115460.887417 line     String#unpack    <internal:pack>:257
18616920:115460.887421 line     #    bug.rb: 6
18616920:115460.887424 call     String#unpack    <internal:pack>:256
18616920:115460.887427 line     String#unpack    <internal:pack>:257
18616920:115460.887430 line     #    bug.rb: 6
18616920:115460.887433 call     String#unpack    <internal:pack>:256
18616920:115460.887437 line     String#unpack    <internal:pack>:257
18616920:115460.887440 c-return Integer#times    bug.rb: 5

ログを見るとString#unpackRubyのメソッドとして呼び出されていますが、どうやらreturnされていないようです。

これが挙動が異なっている箇所のようです。

ちなみにruby 3.0.0dev (2020-09-03T21:41:58Z master d4585e7470) [x86_64-linux]だと正しくreturnされていました。

47044487789240:115847.614876 line     #    bug.rb: 5
47044487789240:115847.614956 c-call   Integer#times    bug.rb: 5
47044487789240:115847.614966 line     #    bug.rb: 6
47044487789240:115847.614972 call     String#unpack    <internal:pack>:256
47044487789240:115847.614977 line     String#unpack    <internal:pack>:257
47044487789240:115847.614983 return   String#unpack    <internal:pack>:258
47044487789240:115847.614990 line     #    bug.rb: 6
47044487789240:115847.614993 call     String#unpack    <internal:pack>:256
47044487789240:115847.614996 line     String#unpack    <internal:pack>:257
47044487789240:115847.615000 return   String#unpack    <internal:pack>:258
47044487789240:115847.615004 line     #    bug.rb: 6
47044487789240:115847.615007 call     String#unpack    <internal:pack>:256
47044487789240:115847.615010 line     String#unpack    <internal:pack>:257
47044487789240:115847.615013 return   String#unpack    <internal:pack>:258
47044487789240:115847.615016 line     #    bug.rb: 6
47044487789240:115847.615018 call     String#unpack    <internal:pack>:256
47044487789240:115847.615021 line     String#unpack    <internal:pack>:257
47044487789240:115847.615024 return   String#unpack    <internal:pack>:258
47044487789240:115847.615027 line     #    bug.rb: 6
47044487789240:115847.615030 call     String#unpack    <internal:pack>:256
47044487789240:115847.615033 line     String#unpack    <internal:pack>:257
47044487789240:115847.615036 return   String#unpack    <internal:pack>:258
47044487789240:115847.615039 c-return Integer#times    bug.rb: 5

修正箇所を探してみる

Ruby 2.7からはいくつかのメソッドはRuby(とC)で実装されています。今回のString#unpackRubyで実装されているメソッドです。

なので、RubyRubyを実装している関連の部分で意図した処理が出来ていない可能性がありそうです。
現在のmasterでは修正されていることから関連しそうな箇所を洗ってみました。

builtin.cString#unpackが実装されているpack.rbなどのコミットログを漁ってみましたが、それらしいのはなかったですね。

で、VM周りのコードでなにかしら変更がありそうだとアタリをつけてみたところ以下のコミットを見つけました。

github.com

追加されているテストを見る限りString#unpackの挙動関連で修正されているようです。

原因

VM周りは詳しくないのではっきりとはしませんが、VMの命令列でreturn出来ていなかったのが原因かなと。

今後

とりあえず、チケットのほうにはmasterでは修正済みと伝えておいた(チケット作った人の意図が僕の認識とあってればだけどね)

あと、バックポートした方が良いんじゃないかとは投げといた。だれもやらなさそうなら該当のコミットをcherry-pickするとかしてpull requestにするかな

追記

昨日の段階でバックポートされてたみたい

bugs.ruby-lang.org

github.com