Ruby/Rails Benchmarking and Profiling with TDD

Slide 1

Slide 1 text

Ruby/Rails Benchmarking and Proﬁling with TDD 2019/09/14 Osaka Ruby Kaigi02 Yasutomo Uemori (wakaba260)

Slide 2

Slide 2 text

me.inspect => { “HN”: "wakaba260", “name”: "Yasutomo Uemori", “company”: "株式会社Aiming", “twitter”: "https://twitter.com/wakaba260yen", “github”: "https://github.com/yuemori", “skills”: ["rails api", "docker", "kubernetes", "GCP"] }

Slide 3

Slide 3 text

突然ですが

Slide 4

Slide 4 text

Ruby/Railsのプロファイルやベンチマーク

Slide 5

Slide 5 text

とったことある人？

Slide 6

Slide 6 text

今日の話はこんな人向けの話 - Ruby/Railsのベンチマークやプロファイリングに興味がある - パフォーマンス改善にどう手を付けていいかわからない　⇛　主に初心者向けの話

Slide 7

Slide 7 text

Agenda 話すこと - Benchmark and Performance Testing - チューニングを行ったときの取り組み話さないこと - Rackサーバのチューニング - 改善をしたときの実装内容

Slide 8

Slide 8 text

Benchmark and Performance Testing

Slide 9

Slide 9 text

はじめに大事なこと

Slide 10

Slide 10 text

推測するな計測せよ

Slide 11

Slide 11 text

プログラミングで時間がかかっている場所を推測してはいけない。

Slide 12

Slide 12 text

どうやって計測しよう🤔

Slide 13

Slide 13 text

Testing そうだ、テストを書こう

Slide 14

Slide 14 text

なぜTestを書くのか我々は普段からアプリケーションに対しテストを書いている - エラーがないこと - バグが修正されたこと - 仕様どおりに動くことこういったことを再現性高く保証するためにテストがある　⇛　パフォーマンスについてもテストを書きたい

Slide 15

Slide 15 text

Red Green Refactor Standard TDD

Slide 16

Slide 16 text

Benchmark Profile Refactor Performance TDD

Slide 17

Slide 17 text

Benchmark Profile Refactor 実行速度を計測

Slide 18

Slide 18 text

Benchmark Profile Refactor 原因箇所を特定

Slide 19

Slide 19 text

Benchmark Profile Refactor コードを改善

Slide 20

Slide 20 text

Benchmark Profile Refactor 改善されたことを確認

Slide 21

Slide 21 text

Benchmark Profile Refactor Measure Measure Improve

Slide 22

Slide 22 text

Benchmark Profile Refactor Measure Measure Improve 計測、計測、そして改善

Slide 23

Slide 23 text

💎今回テストを書くのに使ったgemたち・Testing：RSpec ・Benchmark：module Benchmark ・Proﬁle：https://github.com/tmm1/stackprof

Slide 24

Slide 24 text

Benchmark プロファイリングとあわせてベンチマークは必ずとっておこう - 実際にどのぐらい時間がかかるか？を把握する - プロファイリングを有効にすると、実行速度自体が下がる - 一回だけの実行ではばらつきが出やすいのでウォームアップや実行回数もポイント

Slide 25

Slide 25 text

Benchmark module ・公式のベンチマークライブラリ・簡単な計測ならこれだけで十分

Slide 26

Slide 26 text

Proﬁling 速度計測後はプロファイリングを行い、ボトルネックを特定する - 速度を計測したあと、どこが遅いかを推測で直さない - 利用しているミドルウェアや外部サービスが遅いなどもある程度わかる

Slide 27

Slide 27 text

Stackprof a sampling call-stack proﬁler for ruby 2.1+ ・mode, interval, outを指定してサンプリング対象のコードを　ブロックで呼び出すだけ・CPU Clock Time: CPUの利用時間。　Wall Clock Time: 開始から終了までの時間。Railsの場合はこれ　参考：https://scoutapm.com/blog/profiling-rails-with-stackprof

Slide 28

Slide 28 text

Stackprof

Slide 29

Slide 29 text

Stackprof 総サンプリング回数

Slide 30

Slide 30 text

Stackprof そのメソッドが呼び出しているメソッドの時間も含めた、 TOTALのサンプリング回数

Slide 31

Slide 31 text

Stackprof 純粋にそのメソッドのサンプリング回数

Slide 32

Slide 32 text

Stackprof 処理に時間がかかっている箇所

Slide 33

Slide 33 text

Stackprof 呼び出している処理のため、時間がかかっている箇所

Slide 34

Slide 34 text

Stackprof-webnav

Slide 35

Slide 35 text

Stackprof-webnav 行単位で時間がかかっている箇所を表示できる

Slide 36

Slide 36 text

Stackprof-webnav 一番時間がかかっている場所を特定！

Slide 37

Slide 37 text

Stackprof --ﬂamegraph ・上記のようなﬂamegraphのhtmlを生成してくれる・呼び出しのスタックトレースや時間などが可視化されるので便利

Slide 38

Slide 38 text

実践 https://github.com/yuemori/performance_test_app demo1 demo2

Slide 39

Slide 39 text

最低限のテストは出来るようになった

Slide 40

Slide 40 text

Problem ?

Slide 41

Slide 41 text

Problem めんどくさい

Slide 42

Slide 42 text

Problem めんどくさい・手動実行に頼っている・目視確認に頼っている　⇛　一度直った問題が再発してないかを確認しにくい　⇛　もっと複雑なケースだとテストケースの再現性も問題

Slide 43

Slide 43 text

Performance Spec

Slide 44

Slide 44 text

Performance Spec

Slide 45

Slide 45 text

Performance Spec

Slide 46

Slide 46 text

詳細 https://github.com/yuemori/performance_test_app

Slide 47

Slide 47 text

余談既にそういったgemがあることに後から気づいた - https://github.com/piotrmurach/rspec-benchmark - https://github.com/rails/rails-perftest また必要になったときにはこれらを使うかどうかも検討したい

Slide 48

Slide 48 text

ここまでのまとめ手早くパフォーマンス改善を行うためにはどうしたらいいか - パフォーマンスチューニングにおいては計測が重要 - いろんなgemを使って計測を楽にする - 計測とチューニングのサイクルを確立する

Slide 49

Slide 49 text

パフォーマンス改善時のとりくみ

Slide 50

Slide 50 text

パフォーマンス改善時の取り組み - 改善箇所の調査 - パフォーマンステスト - パフォーマンス改善方法論の共有

Slide 51

Slide 51 text

社内テスト内容から遅いAPIの調査 - 改善箇所を検討するために遅いAPIはどこかを調査 - アクセスログからレポートを作成 - 指標 - 総リクエスト数 - 平均レスポンス速度 - 最大レスポンス速度 - 50%、90%、99%、99%...のレスポンス速度

Slide 52

Slide 52 text

社内テスト内容から遅いAPIの調査

Slide 53

Slide 53 text

・・・どこから手を付けていこう？🤔 社内テスト内容から遅いAPIの調査

Slide 54

Slide 54 text

社内テスト内容から遅いAPIの調査：チューニングの検討 - サービスとして遅い箇所が問題になるもの - 例）毎回ログインに時間がかかる - 共通処理で遅いもの - 例）毎回呼び出される認証が遅い - 遅い原因が他の問題を引き起こすもの - 例）N+1問題が原因なためDBへの負荷が懸念される

Slide 55

Slide 55 text

呼び出し頻度は少ないが取得系なので、かなり酷いN+1なことが予想されるので直したい社内テスト内容から遅いAPIの調査

Slide 56

Slide 56 text

同じくN+1っぽいが、ほとんど呼ばれないため優先度を下げる社内テスト内容から遅いAPIの調査

Slide 57

Slide 57 text

平均速度は上位に比べると早いが、速度劣化の仕方が激しいので原因を見ておきたい社内テスト内容から遅いAPIの調査

Slide 58

Slide 58 text

気になるほど遅いわけではないが、呼び出し回数が飛び抜けて高いのでもう少し早くしたい社内テスト内容から遅いAPIの調査

Slide 59

Slide 59 text

社内テスト内容から遅いAPIの調査：計測方法 - ログから計測 - 今回はStackdriver + BigQuery + DataPortal - 構造化ログを出しておくことで集計が容易になる - サービスの利用 - NewRelicやDatadogなど - productionではおすすめ - CIやローカルで実行するのに難がある

Slide 60

Slide 60 text

パフォーマンステスト - 紹介した実装をベースにテスト環境を整備 - DBのボトルネック調査にクエリレポートを追加実装 - ActiveSupport::Notiﬁcationsを使ってクエリをトレース

Slide 61

Slide 61 text

パフォーマンステスト：クエリレポート - railsの提供するイベントから計測、集計 - テスト時に実行されるSQLのレポートを作成して可視化

Slide 62

Slide 62 text

パフォーマンス改善方法論の共有チューニングを個人に依存しないようにしたいと考えていた - 実際にチューニングを行ったときのことをチーム内勉強会で共有 - ドキュメントの作成　⇛　方法論を共有することでチューニングをチームのものにする💪

Slide 63

Slide 63 text

パフォーマンス改善方法論の共有：ドキュメントの作成

Slide 64

Slide 64 text

パフォーマンス改善方法論の共有：ドキュメントの作成

Slide 65

Slide 65 text

パフォーマンス改善方法論の共有：レビュー - パフォーマンス改善のPRを出した時はdescriptionに結果を記載 - 改善時にチェックしたポイントをわかりやすくする - before/afterを掲載して改善されていることを伝える

Slide 66

Slide 66 text

パフォーマンス改善方法論の共有：レビュー

Slide 67

Slide 67 text

パフォーマンス改善方法論の共有：レビュー

Slide 68

Slide 68 text

まとめ - パフォーマンス改善の心得：推測するな、計測せよ - パフォーマンスのテストコードを書いて改善を楽にしよう - パフォーマンス改善は楽しいので是非Tryしてみてください

Slide 69

Slide 69 text

ご静聴ありがとうございました