ブログ版

IRCログを記録するRailsアプリの開発中、IRCメッセージの解析において、文字が制御文字か判断する必要があった。その際に case-when で文字列の Range とマッチさせる（Range#=== を呼び出す）と、予想外に遅くなった。ruby-profでボトルネックを調べると、ActiveSupport::CompareWithRange#===という見慣れないメソッドが実行されて、時間がかかっているようだった。そこで、通常の Range#=== と実行速度がどのくらい違うか、ベンチマークをとってみた。

ベンチマークのコード

詳細はGitHubのリポジトリを参照。

IRCメッセージの解析では、各文字が制御文字か調べることを行う。そこで、String#each_char の中で ActiveSupport::CompareWithRange#=== または Range#=== を呼び出すプログラムの実行速度を計測することにした。コードは以下のとおり。

char_range_eq3_benchmark.rb

# frozen_string_literal: true

require 'benchmark_driver'

Benchmark.driver do |x|
  x.prelude <<~RUBY
    class Range
      alias old_eq3 ===
    end

    require 'active_support/core_ext/range/compare_range'

    r = "\\x00"..."\\x20"

    # Example from https://modern.ircdocs.horse/formatting.html#examples
    s = "Rules: Don't spam 5\\x0313,8,6\\x03,7,8, and especially not \\x029\\x02\\x1D!"
  RUBY

  x.report 'Default ===', %q! s.each_char { |c| r.old_eq3(c) } !
  x.report 'Active Support ===', %q! s.each_char { |c| r === c } !
end

このスクリプトでは、MJITのk0kubunさんが作られたgemのBenchmarkDriverを利用して、オーバーヘッドを少なくしている。繰り返し前に実行される x.prelude において、Active Supportの読み込み前に alias を使用して、通常の Range#=== に old_eq3 という別名をつけておく。2つの x.report が、繰り返し実行される処理。解析対象の文字列は、IRCメッセージの形式の説明に例として載っていたもの。

実行環境

Mac mini (2018)
- CPU：Intel Core i7 3.2 GHz 6コア
- メモリ：DDR4 2667 MHz 16 GB
- SSD 256 GB
- macOS Catalina 10.15.7
Ruby 3.0.1

実行結果

実行結果を以下に示す。

$ bundle exec ruby char_range_eq3_benchmark.rb
Warming up --------------------------------------
         Default ===    55.360k i/s -     58.740k times in 1.061047s (18.06μs/i)
  Active Support ===    44.636k i/s -     48.455k times in 1.085554s (22.40μs/i)
Calculating -------------------------------------
         Default ===    55.020k i/s -    166.081k times in 3.018555s (18.18μs/i)
  Active Support ===    45.137k i/s -    133.908k times in 2.966715s (22.15μs/i)

Comparison:
         Default ===:     55020.0 i/s
  Active Support ===:     45136.8 i/s - 1.22x  slower

「ActiveSupport::CompareWithRange#=== は通常の Range#=== よりも1.22倍遅い」という結果が得られた。alias で別名をつけたメソッドの呼び出しでこの結果なので、Active Supportによって Range#=== が上書きされていないときに === を呼び出したら、もっと速くなるのかもしれない（未確認）。

原因

ActiveSupport::CompareWithRange#=== が遅い原因は、右辺に Range を指定できるように処理が追加されていること。右辺値が Range かどうかで分岐する。今回は String を渡しているので else 節で単に super が呼び出されるだけだが、比較に時間がかかるのだろう。

active_support/core_ext/range/compare_range.rb#L16-L28

    def ===(value)
      if value.is_a?(::Range)
        is_backwards_op = value.exclude_end? ? :>= : :>
        return false if value.begin && value.end && value.begin.public_send(is_backwards_op, value.end)
        # 1...10 includes 1..9 but it does not include 1..10.
        # 1..10 includes 1...11 but it does not include 1...12.
        operator = exclude_end? && !value.exclude_end? ? :< : :<=
        value_max = !exclude_end? && value.exclude_end? ? value.max : value.last
        super(value.first) && (self.end.nil? || value_max.public_send(operator, last))
      else
        super
      end
    end

しかし、Ruby 2.6以降では、標準の Range#=== も Range を受け取れるようになっている（Feature #14473）。したがって、この部分は、Ruby 2.5以下でも同じ挙動となるように残されているものと思われる。将来はこの部分が削除されて、実行速度が向上する（標準の Range#=== と同等になる）のかもしれない。

まとめ

Active Supportを使うと Range#=== が遅くなる。原因は、ActiveSupport::CompareWithRange#=== において、右辺に Range を指定できるように処理が追加されているためだった。

Active Supportを使うと Range#=== が遅くなる

ベンチマークのコード

実行環境

実行結果

原因

まとめ