はじめに
こんにちは、トレーディングシステム開発運用部の宮下です。今回初めて RubyKaigi2023 に参加しました。 このブログでは、個人的に一番おもしろかったセッション Understanding the Ruby Global VM Lock by observing it について実際にコードを動かして深掘っていこうと思います。
セッションについて
今回ご紹介するセッションは Datadog の Ivo Anjo さんのセッションとなります。 Ruby には 以下のような機能を提供するために Global VM Lock(以下 GVL) という機構が存在します。
- Mutex
- ConditionVariable
- Queue, SizedQueue
- concurrent-ruby gem …
GVL は、Ruby のパフォーマンスに影響を与えるものらしいです。 このセッションでは、gvl-tracing gem を用いてGVLが問題が発生するパターンについて解説してくれました。
gvl-tracing gem
gvl-tracing は、スレッドの状態を可視化してくれるツールです。使い方は、以下の通りです。
require "gvl-tracing" def fib(n) return n if n <= 1 fib(n - 1) + fib(n - 2) end GvlTracing.start("example1.json") Thread.new { sleep(0.05) while true } sleep(0.05) 3.times.map { Thread.new { fib(37) } }.map(&:join) sleep(0.05) GvlTracing.stop
参照 github.com
上記プログラム実行後、生成されるexample1.jsonをPefettoにアップロードすると以下のようにスレッドの状態が可視化することができます。
各状態について
ネットワーク、IO、sleep 等を待機している状態
処理を行っている状態
GVL によって実行する必要がある処理を行えない状態
ガーベージコレクションを行っている状態
wants_gvl が多いと実行する必要がある処理が止まっている状態であるため、GVLによってパフォーマンスが悪化しているという意味になります。 running は処理を行っている状態、waiting は、待機状態(別の処理を行える状態)であるため、この2つは多くても問題にはなりません。
本題
私がこのセッションを見て、実際のスレッドベースでリクエストを処理するWebサーバでも GVL が問題になるかと気になりました。 Ivo Anjo さんも 「Don’t guess: experiment and measure!」とおっしゃっているので、Webサーバに導入して、測定してみたいと思います。 gvl-tracing は Ruby 3.2 が必要です。検証のために新しく Rails アプリケーションを作成しました。
環境
Ruby: 3.2.2
Rails: 7.0.5
MySQL: 8.0.33
puma: 5.6.5
Rails アプリケーションを作成し、 gvl-tracing を起動時に実行するよう変更
# config/initializers/gvl-tracing.rb require "gvl-tracing" GvlTracing.start(".tmp/rails-gvl-tracing-#{Time.now.strftime("%Y%jT%H%MZ")}.json")
次に、以下のAPIを作成しました。
# app/controllers/application_controller.rb class ApplicationController < ActionController::Base def counter_loop puts "/counter_loop Thread id #{syscall(178)}" counter = 0 counter += 1 while counter < 1_000_000_000 render json: "ok!" end def mysql_sleep puts "/mysql_sleep Thread id #{syscall(178)}" ActiveRecord::Base.connection.execute("SELECT SLEEP(1);") render json: "ok!" end def gvl_tracing_end GvlTracing.stop render html: "gvl_tracing_ended!" end end
Rails アプリケーション終了時に GvlTracing.stop を呼び出すようにしたかったのですが、いい方法が見つからず、APIを作成して、gvl-tracing を停止させるようにしています。
続いて、ルーティングの設定を行いました。
Rails.application.routes.draw do get "counter_loop", to: "application#counter_loop" get "mysql_sleep", to: "application#mysql_sleep" get "gvl_tracing_end", to: "application#gvl_tracing_end" end
今回は、CPUを多く使うAPIとデータベースからのレスポンス待ちが発生するAPIの２つを作成しました。
/counter_loop- CPU を使うAPI/mysql_sleep- データベースからのレスポンス待ちが発生するAPI
計測
ケース1: CPU を使うAPI(/counter_loop)を並列で呼び出す場合
Webサーバ側のスレッドを10個を指定し、Webサーバを立ち上げ、クライアントは並列で10回 /couter_loop をリクエストし、スレッドの状態を見てみます。
require 'net/http' def perform_request Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/counter_loop') end end threads = 10.times.map { Thread.new { perform_request } } threads.map(&:join) def gvl_tracing_end Net::HTTP.start('localhost', 3000) do |http| http.get('/gvl_tracing_end') end end gvl_tracing_end
ケース1では、10リクエストそれぞれにスレッドが割り当てられ、実行するスレッドを100msごと切り替えてることがわかります。
ケース2: データベースからのレスポンス待ちが発生するAPI(/mysql_sleep)をリクエストする場合
Webサーバ側のスレッドを2個指定し、Webサーバを立ち上げ、/mysql_sleep のスループットを計測します。
require 'net/http' require 'benchmark/ips' def mysql_sleep Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/mysql_sleep') end end Benchmark.ips do |x| x.config(time: 20, warmup: 0) x.report("request") { mysql_sleep } end ....
ケース2では、ほとんど waiting になっていることがわかります。/mysql_sleepでは、MySQLにクエリを投げレスポンスを待つだけだからです。
20秒あたりのスループットが18となりました。
$ bundle exec ruby gvl-tracing-test5-2.rb
Calculating -------------------------------------
mysql_sleep 0.910 (± 0.0%) i/s - 18.000 in 20.085182s
ケース3: CPU を使うAPI(/counter_loop) と データベースからのレスポンス待ちが発生するAPI(/mysql_sleep) を同時にリクエストする場合
Webサーバ側のスレッドを2個指定し、Webサーバを立ち上げ、/counter_loop をリクエストするのと同時に /mysql_sleep にもリクエストしスループットを計測します。
require 'net/http' require 'benchmark/ips' def counter_loop Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/counter_loop') end end def mysql_sleep Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/mysql_sleep') end end thread = Thread.new { counter_loop } Benchmark.ips do |x| x.config(time: 20, warmup: 0) x.report("mysql_sleep") { mysql_sleep } end thread.join ...
ケース3の結果をみると /counter_loopのリクエストを処理しているスレッド(36526)はほとんど running であることがわかります。
また、 /mysql_sleepのリクエストを処理しているスレッド(36525)の多くの時間が wants_gvl であることがわかります。
/mysql_sleepの処理のほとんどがMySQLからのレスポンス待ちであるため、 /mysql_sleepの処理を優先させ、待ち時間に /counter_loopの処理を行うようにスケジューリングさせれば、効率的にリソースを使えるように思えます。
ケース2に比べ /mysql_sleep の20秒あたりのスループットが 18 → 2 と大幅に下がりました。
$ bundle exec ruby gvl-tracing-test6-2.rb
Calculating -------------------------------------
mysql_sleep 0.155 (± 0.0%) i/s - 2.000 in 20.748499s
ケース4: Ractor を使い /counter_loop_async APIを作成 - CPU を使うAPI(/counter_loop_async) と データベースからのレスポンス待ちが発生するAPI(/mysql_sleep) を同時に呼び出す場合
セッションで Ractor は並列で実行することができると教えてもらいました。
Ractor は Ruby 3.0 で導入された新しい並列実行モデルです。
Ractor を使い新しく /counter_loop_async を作成してみます。
# app/controllers/application_controller.rb ... def counter_loop_async puts "/counter_loop_async Thread id #{syscall(178)}" r = Ractor.new do counter = 0 counter += 1 while counter < 1_000_000_000 counter end puts r.take render json: "ok!" end ...
Webサーバ側のスレッドを2個を指定し、Webサーバを立ち上げ、/counter_loop_async をリクエストするのと同時に /mysql_sleep にもリクエストしスループットを計測します。
require 'net/http' require 'benchmark/ips' def counter_loop_async Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/counter_loop_async') end end def mysql_sleep Net::HTTP.start('localhost', 3000, read_timeout: 60*5) do |http| http.get('/mysql_sleep') end end thread = Thread.new { counter_loop_async } Benchmark.ips do |x| x.config(time: 20, warmup: 0) x.report("mysql_sleep") { mysql_sleep } end thread.join
ケース4の場合、wants_gvl の状態がなく、running とwaiting しかありません。また、wants_gvlの状態がほとんど見当たらず、効率的にリソースが使えているように思えます。
各 Ractor オブジェクトは、GVLを保持していため、wants_gvl の状態にならず、パフォーマンスが改善されました。
/mysql_sleep の20秒あたりのスループットがケース2と同じくらいの値となりました。
$ bundle exec ruby gvl-tracing-test7-2.rb Calculating ------------------------------------- mysql_sleep 0.937 (± 0.0%) i/s - 19.000 in 20.626488s
終わりに
今回は、gvl-tracing gem を用いて、以下を確認することができました。
- スレッドは、100msごと、または、ネットワーク、IO、sleepのタイミングでスイッチされる
- GVLの問題は、スレッドベースでリクエストを処理するWebサーバでも発生してしまう
- Ractor を使うと GVL の一部の問題が解決できそうなことがわかりました
Ractor は、まだ実験段階であり、制約も多いですが、今後に期待ですね。
最後に宣伝させてください。
私が所属するトレーディングシステム開発運用部はエンジニアを募集中です！詳しくは求人ページをご覧ください。
https://hrmos.co/pages/coincheck/jobs/0000278hrmos.co
またコインチェックに興味がある方に向けて社内の情報をゆるく発信していくCoincheck FMも配信しているので、よろしければ聞いてみていただけると幸いです。
