Mastodonをv3系に上げたらDB負荷が激増した話(と解消してコントリビュートした話)
こんにちは! フィフス・フロアのnotozekiです。今年は記事書いてくイヤーにしたいと目論んでいます
先日、ichiji.socialというMastodonサーバーをv2.7.3から一気にv.3.0.1までアップグレードしました。
このアップグレード直後、DBサーバの負荷が異常に高まるという現象が発生し、解決に苦戦したので、そのときの知見を共有したいと思います
また、最後にも記載していますが、解決策を本家MastodonにPull Requestとして送っています。記事執筆時点ではまだマージされていませんが、もし同様の問題に悩んでいる方がいればこちらをお試しください(2020/01/22 追記: マージされました!):
Fix slow query of federated timeline by notozeki · Pull Request #12886 · tootsuite/mastodon
v3にアップデート直後、DBのCPU使用率が跳ね上がる
最初に異変に気づいたのは、メンテ後にStackdriverで負荷状況を様子見していたときでした。
メンテナンス自体は大きな問題もなく終了したので、一件落着と思ってグラフを一通り追っていくと…
なんと、DBサーバーのCPU使用率が跳ね上がっています1
何が起こっていた?
結論から言うと、「連合タイムライン」で発行されるSQLクエリの実行に非常に時間がかかるという現象でした。
以下が、この現象が起きていた時の実際のPgHeroの画面のスクリーンショットです。
このように、いくつもlong runningなクエリが走っている状態でした。この中で一番長いものでは、約1,200,000ms=1200秒=20分(20分)も走っているクエリがあります。これらのクエリがDBのCPUを喰い潰しているようでした。
このクエリは、連合TLで使われているAPI(GET /api/v1/timelines/public
)で発行されていることがわかりました。ロードバランサのログにも、以下のように 504 (=Gateway Timeout、つまりバックエンドサーバが一定時間内に応答できなかった) のログが並んでいました。
幸い、サービス全体が重くなったりすることはなく、また↑のエラーもすべての連合TLのAPI呼び出しで出ていたわけではなかったのですが、いずれにせよDBの負荷が高いまま放っておくわけにはいきません。
解決策を見つけるまで
ここまではわかったものの、解決策にたどり着くのに苦労しました。
経験上、このようなメジャーな不具合は、既にIssueとして報告されていたり、修正のPRがあることがほとんどです。今回もそうだろうと思ってMastodonのリポジトリのIssueやPRを追いかけたのですが、一向に同じ報告が見つからず焦りました。
かろうじて、以下のIssue(と解決のPR)が見つかりました。ほぼ同様の現象ですが、このIssueでは「ローカルタイムライン」のみが問題となっていました2。
- LTL is not displayed after applying #11623 in some instance · Issue #11643 · tootsuite/mastodon
- Fix slow local timeline query by Gargron · Pull Request #11648 · tootsuite/mastodon
上記の問題は、ローカルTLのAPIで発行される特定のSQLクエリの検索パフォーマンスが良くないことでした。それを改善するために、#11648では以下のようなマイグレーションで新たなインデックスを作成しています。
add_index :statuses, [:id, :account_id], name: :index_statuses_local_20190824, algorithm: :concurrently, order: { id: :desc }, where: '(local OR (uri IS NULL)) AND deleted_at IS NULL AND visibility = 0 AND reblog_of_id IS NULL AND ((NOT reply) OR (in_reply_to_account_id = account_id))'
注目すべき点はwhere
オプションです。これを指定すると「部分インデックス」が作られます。部分インデックスは、この条件に合致するレコードのみを対象とするインデックスで、上記のwhere
条件はローカルTLのクエリに合わせて作られているようでした。
これを連合TL用にも作れば解消するのでは、というのが今回の解決策の着想です。つまり、上記のwhere
条件を連合TL向けに少し緩くしたインデックスを作ってみます。
インデックスを作るとCPU使用率が劇的改善
幸い、インデックスを作るだけなら、アプリケーションコードをいじらなくても試すことができます。以下のSQLを本番DBに発行して、インデックスを作ってみました3。
CREATE INDEX CONCURRENTLY index_statuses_public_20200117 ON statuses USING btree (id DESC, account_id) WHERE ((deleted_at IS NULL) AND (visibility = 0) AND (reblog_of_id IS NULL) AND ((NOT reply) OR (in_reply_to_account_id = account_id)));
するとどうでしょう、あれだけ高かったDBの負荷が一瞬にして下がりました!
インデックスすごい…
本家MastodonにPull Requestを送る
直った! ということでこれで終わりでもよいのですが、せっかく解決できたので、本家Mastodon (https://github.com/tootsuite/mastodon) にもコントリビュートしましょう。
というわけで、上記のインデックス作成をマイグレーション化して、Pull Requestにして送りました。
Fix slow query of federated timeline by notozeki · Pull Request #12886 · tootsuite/mastodon
実は、外部のOSSプロジェクトにPRを送るのはこれが初めてでした。送るまでは結構「内容はこんな感じでいいんだろうか…」とか「英語ちゃんと伝わるんだろうか…」とかドキドキしていたのですが、翌朝にはapproveされていてホッとしました。というか送って1時間ほどでレビューが付いていてビビりました
まだマージされていませんが、よしななタイミングでメンテナの方がマージするようなのでそれ待ちです。
2020/01/22 追記 マージされました
https://github.com/tootsuite/mastodon/pull/12886#event-2967198280
まとめ
- インデックスはすごい
- 「IssueやPRが既にあるだろう」と思い込んで調べているとドツボにハマる
- IssueやPRが無い問題を見つけたらせっかくならコントリビュートしよう
-
正確には、11:30くらいまでは、アップグレード作業に伴うDBのマイグレーションを回していたので、負荷が高いのは正しい挙動です。しかし、その後もCPU使用率が高いままなのは異常です。 ↩
-
このIssueには「連合TLは前と同じくらい早い」ということが書かれていて、最初は「じゃあ今回の件とは関係ないか…」と一旦除外していたのですが、結局このIssueと原因は同じことがわかりました。 ↩
-
CONCURRENTLY
をつけると、テーブルをロックせずにインデックスを作ることができるため、稼働中のサービスへの影響を最小限に抑えられます。ただし、CREATE INDEX
に少し時間がかかります。これは#11648でも使われていたのを真似しました。 ↩
Author And Source
この問題について(Mastodonをv3系に上げたらDB負荷が激増した話(と解消してコントリビュートした話)), 我々は、より多くの情報をここで見つけました https://qiita.com/notozeki/items/ca196b77e89a10cd1e1e著者帰属:元の著者の情報は、元のURLに含まれています。著作権は原作者に属する。
Content is automatically searched and collected through network algorithms . If there is a violation . Please contact us . We will adjust (correct author information ,or delete content ) as soon as possible .