Slide 1

Slide 1 text

未知の原因によるDB負荷の 上昇とその対応プロセス 清⽔⼤樹 2024年6⽉1⽇

Slide 2

Slide 2 text

2 清水大樹
 2020年4月 freee新卒入社
 freee会計やfreee販売などのアプリケー ション開発チームを経て現在 DBRE チー ム所属
 全社にまたがるデータベースのパフォーマ ンスや運用の改善に従事
 Database Reliability Engineering (DBRE) チーム Engineer

Slide 3

Slide 3 text

  今回話すこと freee 特有の季節性イベントで発⽣したデータベース負荷と、 その解決に向けて⾏ったアプローチについて紹介します。

Slide 4

Slide 4 text

  ⽬次 ● 季節性イベントによる負荷の上昇 ● 収束までの対応プロセス ● 問題収束後の取り組み ● まとめ

Slide 5

Slide 5 text

  季節性イベントによる 負荷の上昇

Slide 6

Slide 6 text

  freee のデータベース利⽤状況 ● RDBMS には Amazon Aurora for MySQL を採⽤している ○ Aurora2 (MySQL 5.7互換)とAurora3 (MySQL 8.0互換) が混在 ○ Writer/Reader 構成 ● 各プロダクトは原則として 1 つ以上の RDBMS を持つ ○ 本番環境で数⼗クラスタが稼働中

Slide 7

Slide 7 text

  今回 DB 負荷が上昇したプロダクトの構成 ● Rails 6 製のアプリケーション ○ ORM として ActiveRecord を利⽤ ● 接続先の DB が複数ある ○ いずれも Aurora2 (MySQL 5.7互換) ● ワークロードとして書き込みが多いことに加え Writer インスタンスに流れている SELECT クエリも多い

Slide 8

Slide 8 text

  Performance Insights によるモニタリング ● Performance Insights の有効化で可視化されるもの(⼀部) ○ DBLoad とその内訳 ○ 負荷が⼤きいクエリの統計情報 ● 負荷の指標としては DBLoad を重要視している ○ アクティブなセッションの同時実⾏数の平均 ○ vCPU 数を超えると性能が劣化し始める傾向がある

Slide 9

Slide 9 text

  ● 内部的な処理(待機イベント)ごとに使われている時間 ○ 待機イベントは MySQL の Performance Schema の イベントに対応 ○ 例: synch/cond/innodb/row_lock_wait が増えていると、 ⾏ロック待ちに時間が使われていることが分かる DBLoad の内訳

Slide 10

Slide 10 text

  ● 毎年同時期にリクエストが増加するイベント ○ 2-3 ヶ⽉ほどかけて徐々に増え、 さらに期間最後の 1 週間程で急激に負荷が増える ● 事前にキャパシティプランニングを⾏いリソースを増強 ○ 過去の傾向をもとに DB もインスタンスクラスを上げていた 季節性イベント イベント期間最終⽇にかけて増え続ける qps の様⼦

Slide 11

Slide 11 text

  ● 突然サービスのレスポンスが著しく悪化 ● DB の CPU やメモリなどのリソースには余裕があった ○ キャパシティプラニングの範囲内 ● Writer インスタンスで DBLoad が⼤きく上昇していた 期間中の急激な負荷上昇

Slide 12

Slide 12 text

  ● DBLoad の⼤部分は過去の運⽤で⾒たことのない 謎のイベント fil_space_latch ● 遅くなっているクエリの対象テーブルに⼀貫性がない ● いったん⾃然に収束したものの、 原因不明でいつ再発してもおかしくない状態 期間中の急激な負荷上昇

Slide 13

Slide 13 text

  収束までの対応プロセス

Slide 14

Slide 14 text

  ● CPU やメモリなどリソース的な観点では問題がなかった ● DBLoad のベース部分が⼤きくなっていた ○ イベントの性質上書き込みが増えるため、 redo_log_flush イベントが DBLoad を押し上げていた ○ vCPU を超える時間はクエリが遅くなっていたが、 今回の事象ほどの性能劣化を引き起こすレベルではない 原因調査

Slide 15

Slide 15 text

  ● 特徴的だった待機イベント fil_space_latch に注⽬ ○ Aurora や MySQL のドキュメントに説明はなかったため、 mysql-server のソースコードや AWS サポートとのやりとり などを通して情報を収集した ● fil_space_latch は内部⼀時テーブル作成時に発⽣する ラッチ獲得に関するイベントらしいことがわかってきた ○ Performance Insights で上位の SQL にも 内部⼀時テーブルを作成するクエリが多く⼊っていた 原因調査

Slide 16

Slide 16 text

  ● MySQL ではクエリの中間結果を記録するため 暗黙的に内部⼀時テーブルが作成されることがある ● グローバル⼀時テーブルスペース ○ 実体としてはスレッド間で共有されるファイル ○ 内部⼀時テーブル作成でディスク使⽤時にアクセスされる ● スペースへのアクセス時にラッチが獲得される ○ 獲得待ちで記録されるイベントが fil_space_latch 内部⼀時テーブル作成時の動作 Thread (Session) Thread (Session) shared temporary tablespace ‧‧‧ SELECT * FROM t1 JOIN t2 ON t1.id = t2.t1_id ... ORDER BY t2.id SELECT * FROM t3 JOIN t4 ON t3.id = t4.t1_id ... ORDER BY t4.id

Slide 17

Slide 17 text

  ● 「内部⼀時テーブル作成の並列度が上がったことによるラッチ 競合で負荷が上がった」という仮説ができたが確信は持てな かった ○ 同様の原因で問題が発⽣した事例が⾒当たらない ○ ラッチをそれほど⻑く持つような実装をするのかという疑問 ○ アプリケーション変更など他の可能性も捨てきれない 確信を持てない仮説

Slide 18

Slide 18 text

  ● 最⼩限のテストケースを使った実験設計 ○ 内部⼀時テーブルを作るサンプルクエリを作成 ■ JOIN と ORDER BY を組み合わせたクエリ ○ mysqlslap を利⽤してクエリを並列に実⾏ ● fil_space_latch が急激に増えた後 DBLoad が徐々に下がる 様⼦が再現して仮説を確認することができた 仮説検証のための再現実験

Slide 19

Slide 19 text

  ● 検証により原因が特定でき対応すべきポイントが明確になった ○ ⽬標は内部⼀時テーブルを作成するクエリを Write インスタンスから減らすこと ○ 効果がありそうな対策を並⾏に進めることにした 組織横断で並⾏に対策を実施

Slide 20

Slide 20 text

  ● 緊急度の⾼さから組織横断的に並⾏で対策を打っていった ○ DB パラメータの調整 ○ アプリケーションコードの修正 ○ ActiveRecord の対応 組織横断で並⾏に対策を実施 DB Product プロダクト チーム プロダクト チーム ‧‧‧ ‧‧‧ ‧‧‧ DBRE 基盤チーム ライブラリ‧ ミドルウェア ‧‧‧ アプリケーションコードの 修正 ActiveRecord の対応 DB パラメータの調整

Slide 21

Slide 21 text

  ● max_execution_time を下げる ○ SELECT クエリを強制的に終了させるパラメータ ○ クエリが滞留した場合に捌けるまでの時間を短くする狙い ○ セッションレベルの設定で⼀部のクライアントに設定 DB パラメータの調整

Slide 22

Slide 22 text

  ● tmp_table_size (max_heap_table_size) を上げる ○ 各セッションで内部⼀時テーブルに使うメモリの最⼤値で、 これを超えるとディスクに書き出し始める ○ OOM を避けるためセッション数やメモリ残量から 値を⾒積もり段階的に上げていった ● fil_space_latch に対する効果を適⽤前に確認 ○ 先述の検証で作成したテストケースを利⽤できた DB パラメータの調整

Slide 23

Slide 23 text

  ● 内部⼀時テーブル作成数が多いクエリを DBRE でリストアップ ● プロダクトチーム側で可能なものは修正 ○ クエリを Reader インスタンスに向ける ○ 内部⼀時テーブルを作成しないようにクエリを修正 アプリケーションコードの修正

Slide 24

Slide 24 text

  ● 内部⼀時テーブルを作成するクエリで最も多かったのは SHOW COLUMNS ... などスキーマ情報を取得するもの ○ ActiveRecord がモデル構築のため DB コネクション作成時に 発⾏していた ○ MySQL5.7 の場合これらのクエリは必ずディスクを使って⼀ 時テーブルを作成するため、 tmp_table_size を変えても効 果がなかった ActiveRecord の対応

Slide 25

Slide 25 text

  ● 事前にスキーマ情報をダンプしたファイルを アプリケーションに読ませてクエリ発⾏をなくす ○ Rails の機能としても存在するが、対象プロダクトで使われ ていた Rails 6 では MultiDB に未対応だった ○ ActiveRecord に Monckey Patch をあてることで解決した ● 結果的にはこの対応による効果が最も⼤きく、 問題の fil_space_latch イベントは発⽣しなくなった ActiveRecord の対応 内部⼀時テーブルの作成数が急激に下がる様⼦

Slide 26

Slide 26 text

  問題収束後の取り組み

Slide 27

Slide 27 text

  継続的な DB 改善活動の強化 ● DB のパフォーマンス改善が進みづらい課題があった ○ 関わる開発者が多い DB はオーナーシップが弱くなりやすい ○ DBRE で課題を⾒つけても、アプリケーションコードに直接 ⼿を⼊れるのは効率が悪い ● DB の運⽤やパフォーマンスの改善を推進するチームが 今回の問題が起きたプロダクトで発⾜ ○ プロダクト内の各機能の開発チームからメンバーが集合 ○ DBRE の知⾒と組み合わせて DB の改善を進め始めている

Slide 28

Slide 28 text

  ● DBLoad 全体の⼤幅な減少 ○ 書き込み中⼼のワークロードであったため⼤きな割合を占め ていた redo_log_flush の処理の性能が向上した ○ ピークタイム同⼠の⽐較で約 2/3 まで減少した ● 内部⼀時テーブルのディスク使⽤率の減少 ○ 内部⼀時テーブル作成に関する実装の変更 ○ ディスクを使いがちだったメタデータへのアクセスが改善 Aurora2 から Aurora3 への移⾏ Aurora2(redo_log_flush がトップ) Aurora3(redo_log_flush がトップではなくなった)

Slide 29

Slide 29 text

  まとめ

Slide 30

Slide 30 text

  まとめ ● 季節性イベントによる負荷の上昇 ○ Rails と MySQL を組み合わせたアプリケーションで 同時実⾏性が⾼い場合に発⽣する問題 ● 収束までの対応プロセス ○ 再現実験による検証を⾏い原因を特定 ○ チーム横断で問題に取り組み早期に収束 ● 問題収束後の取り組み ○ 継続的な DB 改善活動の強化 ○ Aurora3 への移⾏

Slide 31

Slide 31 text

No content