Rails: productionでCPU usageが100%になる問題をデバッグする(翻訳)

概要

原著者の許諾を得て翻訳・公開いたします。

Rails: productionでCPU usageが100%になる問題をデバッグする(翻訳)

production環境のRailsシステムでCPU usageの上昇をデバッグするときはどうやっていますか?


今日、ある顧客のコンテナでCPU usageが異常に高くなっていることに気づきました。

# top -bn1

190 discour+  20   0 2266292 205128  15656 S  86.7  0.3   9377:35 ruby

# ps aux

discour+   190 19.4  0.3 2266292 207096 ?      Sl    2017 9364:38 sidekiq 5.0.5 discourse [1 of 5 busy]

どうもsidekiqのジョブが詰まっているようです。

詰まっている場所はどこでしょうか。

普通ならそこで話はおしまいで、次のような他の疑問に進むところです。

  • staging環境やdevelopment環境で再現できるか?
  • 最近変更されたコードはどれか?
  • perf traceでろくな情報が取れないのはなぜか?
  • Sidekiqのログ出力はどのぐらいイケてるか?
  • 魔法の占い杖はどこかにないのか?

Julia Evansが取り組んでいる素敵なプロファイラを使えば、この種の問題の回答をたちどころに得ることができます。しかしそれまでの間、さしあたって何か打つ手はないものでしょうか?

rbtrace + stackprof

DiscourseのGemfileにはrbtracestackprofが常備されています。

gem 'rbtrace'
gem 'stackprof', require: false

私たちのproduction環境ではrbtraceを常備しているので、多種多様なデバッグをproductionレベルで行えます。stackprofは必要に応じて読み込みます。

今回のような場合なら以下を実行すれば一発です。

# rbtrace -p 190 -e 'Thread.new{ require "stackprof"; StackProf.start(mode: :cpu); sleep 2; StackProf.stop; StackProf.results("/tmp/perf"); }'

これでstackprofをグローバルに有効にする新しいスレッドが1つ注入され、最終的に/tmp/perfにパフォーマンスデータが出力されます。

ダンプの解析は簡単です。

# stackprof /tmp/perf
==================================
  Mode: cpu(1000)
  Samples: 475 (0.63% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       473  (99.6%)         473  (99.6%)     #<Class:0x00007fac08218020>::Typography.to_html_french
         4   (0.8%)           1   (0.2%)     #<Module:0x00007fac080c3620>.reap_connections

実は、stackprofではバックトレースの収集はもちろん、フレームグラフまで生成できるので、READMEをしっかり読んでおくことを強くおすすめします。

いたいた、犯人はこんなところにいました。

text.gsub(/(\s|)+([!?;]+(\s|\z))/, ' \2\3')

正規表現がproductionでCPUを100%使い切っていたのです。🧙‍の最初のお手柄でした。

関連記事

TestProf: Ruby/Railsの遅いテストを診断するgem(翻訳)

デザインも頼めるシステム開発会社をお探しならBPS株式会社までどうぞ 開発エンジニア積極採用中です! Ruby on Rails の開発なら実績豊富なBPS

この記事の著者

hachi8833

Twitter: @hachi8833、GitHub: @hachi8833 コボラー、ITコンサル、ローカライズ業界、Rails開発を経てTechRachoの編集・記事作成を担当。 これまでにRuby on Rails チュートリアル第2版の半分ほど、Railsガイドの初期翻訳ではほぼすべてを翻訳。その後も折に触れてそれぞれ一部を翻訳。 かと思うと、正規表現の粋を尽くした日本語エラーチェックサービス enno.jpを運営。 実は最近Go言語が好き。 仕事に関係ないすっとこブログ「あけてくれ」は2000年頃から多少の中断をはさんで継続、現在はnote.muに移転。

hachi8833の書いた記事

BPSアドベントカレンダー

週刊Railsウォッチ

インフラ

ActiveSupport探訪シリーズ