IRCログを記録するRailsアプリの開発中、IRCメッセージの解析において、文字が制御文字か判断する必要があった。その際に case-when で文字列の Range とマッチさせる(Range#=== を呼び出す)と、予想外に遅くなった。ruby-profでボトルネックを調べると、ActiveSupport::CompareWithRange#===という見慣れないメソッドが実行されて、時間がかかっているようだった。そこで、通常の Range#=== と実行速度がどのくらい違うか、ベンチマークをとってみた。
ベンチマークのコード
詳細はGitHubのリポジトリを参照。
IRCメッセージの解析では、各文字が制御文字か調べることを行う。そこで、String#each_char の中で ActiveSupport::CompareWithRange#=== または Range#=== を呼び出すプログラムの実行速度を計測することにした。コードは以下のとおり。
# 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 が呼び出されるだけだが、比較に時間がかかるのだろう。
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 を指定できるように処理が追加されているためだった。