Tech Racho エンジニアの「?」を「!」に。
  • Ruby / Rails関連

TestProf(3): Rubyテストのプロファイリングを統合・自動化する(翻訳)

概要

元サイトの許諾を得て翻訳・公開いたします。

日本語タイトルは内容に即したものにしました。

TestProf(3): Rubyテストのプロファイリングを統合・自動化する(翻訳)

はじめに

近年は開発エクスペリエンスの強化を求める傾向が高まっており(Evil Martiansでは開発ツールのコンサルティングも行っています)、エンジニアは生産性を最大化するために、さらにスマートなツール、さらに高速なフィードバックループを強く求めています。
Ruby on Railsコミュニティでは、テストが遅いせいでCI/CDビルド時間が長くなることが特に問題視されています。私たちが6年前に導入したTestProfによってRuby開発者たちの作業は楽になり、テストが大幅に高速化されました。TestProfプロジェクトの有効性は実証され、完成したものと思われていますが、TestProfの進化が歩みを止めたことはありません。本記事では、テストプロファイリングのプレイブックの更新と、TestProfツールの新機能を紹介します。

本シリーズは6年前に始まりましたが、このたび最初の2本の記事を全面的に刷新し(訳注: 上記2本の翻訳記事も既に更新いたしました)、さらに今回の更新情報記事を作成しました。しかし、本シリーズで扱ってきたRubyやRailsの遅いテストの問題や、私たちが提案してきたソリューションは現在も通用します。

2018年以降、Railsのメジャーバージョンは2つ、Rubyのメジャーバージョンは1つ進みましたが、テストを遅くしない以下の2つのベストプラクティスについては、ここでは繰り返しません。

  • letlet!ではなくTestProfのlet_it_beを使う
  • before(:each)ではなくTestProfのbefore_allを使う

その代わりに、TestProfとその利用パターンがどのように進化を遂げてきたかについてお話したいと思います。ここでは以下のトピックについて説明します。

🔗 TestProfプレイブックとは

私たち(Evil Martians)は、何十ものRailsアプリケーションと長年取り組み続けています。そして少なくとも、どのRailsアプリケーションのテストスイートにもささやかな愛情注意を向ける必要があります(テストパフォーマンスの向上に特化した案件もありました)。
当然ながら、私たちがこれまで扱ってきたどのケースでも、「テストが遅くなる理由」と「遅いテストスイートへの対処方法」は極めて関連が深いので、そのために以下のフレームワーク(プレイブック)を作成しました。

  • 最初に、ある程度人力によるプロファイリングを行います。
    (アプリケーション設定のチェックや、Gemfileにいつもの常習犯がいないかどうかのチェック)

  • 次に、StackProfのサンプルをSpeedscopeツールで分析します。

  • 次に、TestProf固有のプロファイラ(TagProf、EventProf、FactoryProfなど)を本格的に導入します。

私たち火星人がお客様のプロジェクトに参加することで得られるメリットは、テストの最適化だけではありません。以下の記事にある「クジラに乗ったRuby」セットアップを用いて、後から参加するエンジニアがコマンド一発で開発環境をセットアップ可能にいたします。

クジラに乗ったRuby: Evil Martians流Docker+Ruby/Rails開発環境構築(更新翻訳)



TestProfプレイブックの完全版はtest-prof.evilmartians.io/playbookで入手できます。


TestProfプレイブックは、テストのプロファイリングの出発点として有用ですが、それでも開発者が多くの作業を手動で行う必要があります。遅いテストに取り組んでいる以上、プロファイリング作業でも当然時間がかかってしまいます。そこで私たちは、人間による操作を最小限に抑える方法を検討するうちに、操作を自動化することを思いついたのです。

🔗 TestProf Autopilotによる自動プロファイリング

自動化作業は、プロセスを何らかの整った形式で記述することから始まります。プレイブックの形式がひととおり整備された後で、いよいよ自動化作業に取り掛かる準備ができました。TestProf Autopilotは、このような経緯で誕生したのです。

TestProf Autopilotは、TestProfの複雑なシナリオの実践を支援するCLIツール(gem)です。Rubyで書いたシナリオを自分たちのコードベースに対して実行できます。

test-prof/test-prof-autopilot - GitHub

たとえば、StackProfレポートの生成やマージ作業を自動化して、集計結果を表示するには、以下のスクリプトが使えます。

# spec/.test-prof/stack_prof_scenario.rb

# 最初に、起動時間をプロファイリングする
run :stack_prof, boot: true, sample: 10

save report, file_name: "stack_prof_boot"

# 次に、サンプリングしたプロファイルを複数生成して結果を集計する
aggregate(3) { run :stack_prof, sample: 100 }

save report, file_name: "stack_prof_sample"

続いて、このスクリプトをauto-test-profコマンドで実行します。

bundle exec auto-test-prof -i spec/.test-prof/stack_prof_scenario.rb

Autopilotはプロファイリングを4回実行して、指定の場所にレポートを出力します。これによって、つきっきりでプロファイリングを見張る必要がなくなり、プロファイリングに時間がかかるのを見越して他の作業に専念できます。

シナリオはRubyスクリプトで書くので、プロファイリングのニーズに応じてRuby言語のパワーや表現力を存分に活用できます。

現実のシナリオをもうひとつ紹介しましょう。このシナリオは、指定のグループについて、factoryの実行時間が50%以上を占めるファイルを絞り込みます。

# spec/.test-prof/event_prof_scenario.rb

run :event_prof, event: "factory.create", top_count: 1000

total_run_time = report.raw_report["absolute_run_time"]
total_event_time = report.raw_report["total_time"]

threshold = 0.5 * total_run_time

sum = 0.0
sum_event = 0.0

top_groups = report.raw_report["groups"].take_while do |group|
  next false unless sum < threshold

  sum += group["run_time"]
  sum_event += group["time"]
  true
end

msg = <<~TXT
  Total groups: #{report.raw_report["groups"].size}
  Total times: #{total_event_time} / #{total_run_time}
  Selected groups: #{top_groups.size}
  Selected times: #{sum_event} / #{sum}

  Paths:

TXT

paths = top_groups.map { _1["location"] }

puts msg
puts paths.join("\n")

実行方法は以下のとおりです。

$ bundle exec auto-test-prof -i spec/.test-prof/event_prof_scenario.rb\
  -c "bundle exec rspec spec/models"

Total groups: 497
Total time: 2210.41 / 2394.49
Selected groups: 26
Selected time: 1118.15 / 1199.34

Paths:

./spec/models/appointment_spec.rb:4
./spec/models/user_spec.rb:3
./spec/models/assessment_spec.rb:3
...

このシナリオを実行したおかげで、最適化作業を497ファイル中26ファイルにまで絞り込むことに成功しました。つまり、全ファイルの約5%が実行時間の50%を占めていたのです!

当初はそこまで計画していたわけではありませんでしたが、Autopilotは大規模なコードベース(単一プロセスでテストスイートを実行すると数時間かかるレベル)で特に有用であることがわかってきました。
プレイブックを見てみると、テストスイートをすべて実行することが要求されるステップがいくつかあることがわかります(例: TagProf分析)。

レポートをJSON形式で保存してマージする機能は既にあるので(上述のaggregateの例を参照)、これらの機能をCLIに公開するだけで以下の--mergeオプションを実現できました。

$ auto-test-prof --merge tag_prof --reports tag_prof_*.json

Merging tag_prof reports at tag_prof_1.json, tag_prof_2.json, tag_prof_3.json

[TEST PROF] TagProf report for type

       type          time   factory.create    total  %total   %time           avg

      model     28:08.654        19:58.371     1730   56.44   46.23     00:00.976
    service     20:56.071        16:14.435      808   29.18   28.35     00:01.554
        api     04:48.179        03:54.178      214    7.32    4.78     00:01.346
        ...

しかしレポートの収集はどうすればよいでしょうか?CIでTestProf Autopilotを実行し、レポートを成果物として保存すればよいのです!
以下はシナリオの例です。

run :tag_prof, events: ["factory.create"]

save report, file_name: "tag_prof_#{ENV["CI_NODE_INDEX"]}"

しかしファイルのダウンロードはまだ手動で行う必要がありそうです。これは嬉しくないので、TestProfの今後のリリースでは回避策として#uploadメソッドを追加することを検討しています。この場合、レポートの保存先はクラウド(おそらくTestProf Cloud 😉)になるでしょう。

TestProf Autopilotは、かなり長い間社内プロジェクトとして運営されており、テスト最適化については信頼の置けるパートナーとなっています。現在も(そこそこ)活発に開発が進められていますが、一般公開に耐えうるレベルで十分使える状態です。ぜひ皆さんにもTestProf Autopilotをお試しいただいて、お気づきの点や問題点をお知らせください。

次は、今回のTestProfリリースでその他に準備されているものを見ていきましょう。

🔗 その他の機能と今後の計画

TestProfは3年以上も前にv1.0になり、成熟・安定したソフトウェアとなっています。しかし成熟したからといって新機能がないわけではありません。ここではv1.3.0v1.4.0のハイライトを紹介します。

まず、MemoryProfという新しいプロファイラを導入しました。MemoryProfは、たとえばRSS使用量やオブジェクトアロケーションの急増の原因となるサンプルやグループを特定するのに役立ちます。

「テストのメモリ使用量を気にする必要があるのだろうか?」と疑問に思うかもしれませんね。
第1に、これはCIインフラストラクチャを最適化するためのものです(セルフホスティングであろうとなかろうと、メモリ使用量の増加はコスト増加につながります)。
第2に、この種のプロファイリングはproduction環境のメモリ問題を特定するときにも役立ちます。ぜひMemoryProfをお試しいただき、どんな洞察を得られるかをご覧ください!

私たちが待ち望んでいるもうひとつの機能は、Vernierとの統合です。

jhawthorn/vernier - GitHub

Vernierは、次世代のRubyサンプリングプロファイラで、マルチスレッド/GVL/GCイベントのサポートが強化されています(参考: ウォッチ20240423)。

私が気に入っているVernierの機能の1つは、Active Support Notificationとの統合です。これを用いることで、Railsイベントをスタックトレースに沿って表示できるようになりました。テストが遅い理由を知りたければ、Instrumentationのload_config_initializer.railties項目をチェックしてみることをおすすめします。

Vernierのもうひとつの機能は、Firefox Profiler UIと互換性があることです。以下は、テストスイートがある日突然遅くなった原因をFirefox Profilerで調べているところです(ネタバレ: 原因はSentry.capture_messageです)。

VernieのレポートをFirefox Profilerで分析するデモ


さて、TestProfは今後どうなっていくのでしょうか?
今のところv2に向けた壮大な計画があるわけではありません(ありますが、まだタイムラインに乗せていません)。その代わり、TestProfの世界を拡張して新しいテスト志向ツールを導入することに専念しています。また、モックの信頼性を高めて偽陰性を避けるためのMock Sueyというツールキットもリリースしました。

test-prof/mock-suey - GitHub

私たちは今後、TestProfプレイブックの自動化をさらに推し進め、コンフィグや依存関係を分析して最適化方法を提案するtest-prof-auditのような機能を提供する予定です(プレイブックのログ出力やWisperの例を参照)。

最後に、自動化といえばAIの流行に乗らずにはいられませんね。私たちは既にTestProfのAI化も開始しており、しかも驚くほど順調です!

今後もご期待ください。そしてぜひテスト高速化ムーブメントに参加しましょう(TestProfのスポンサーも募集しています))。

関連記事

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

TestProf(2) Rubyテストの遅いfactoryを診断治療する(翻訳)


CONTACT

TechRachoでは、パートナーシップをご検討いただける方からの
ご連絡をお待ちしております。ぜひお気軽にご意見・ご相談ください。