個人開発のMinecraft監視アプリに負荷試験をしてみた ― 読み取り専用のAPIが、実は毎回DBへ書き込んでいた
前回の記事の最後で、「負荷や長時間稼働に対する挙動は、自動では見ていません」と書きました。個人開発しているMinecraftサーバー監視アプリ「MineWatch」(公式サイト、アプリの全体像はこちら)は、本番のユーザーが8人、監視対象のサーバーが4台という規模です。それでも、staging環境に段階的に負荷をかけて「最初に劣化する点(膝)」を探す試験を実施しました。
結果、想定していなかった問題がいくつも見つかりました。この記事は、その試験の設計と、見つかった問題、直した結果をまとめたものです。
TL;DR
- 本番は8ユーザー・監視対象4台の個人開発規模だが、stagingでその数十〜数百倍の負荷をかけて「膝」を探した。stagingは本番とノード・ingress・DBを共有するので、本番を壊さない安全装置をコードに固定した。
-
一番の驚き: 読み取り専用の
GET /v2/serversが、認証のたびにDBへ書き込んでいた(ログイン時刻の記録)。低負荷でもp50が270msかかる原因の9割は、実はこれではなくID tokenの失効チェック(Googleへの往復)だったが、両方直すとスループットの上限は20 req/s → 60 req/sまで伸びた。 - 監視ワーカーの限界は、SQLの実行時間ではなく**DB接続を1本開くコスト(14ms)で決まっていた。検査ごとに接続を開き直す実装を、接続を使い回す実装に変えたら、正常に処理できる台数が600台 → 1000台以上(測定した範囲では膝が見つからず)**に伸びた。
- SSE(リアルタイム配信)は、Ingressの設定漏れでそもそも何も届いていなかった。直したら、今度はDB接続を握り続ける実装が原因で、15接続を境に無関係な全リクエストまで500になる問題が発覚した。
- 負荷試験ツール自身が固まって、stagingのDB接続を2時間40分握り続け、
adminをクラッシュさせた(本番は無傷)。守るためのツールにも、同じ種類の保護が要ることを身をもって学んだ。
1. なぜ「8ユーザーの個人開発」でも負荷試験をするのか
MineWatchの現在の規模は、ユーザー8人、監視対象4台、履歴が約4.5万行(12MB)です。この規模だけを見れば、負荷試験は明らかに過剰装備です。
それでも試験をした理由は3つあります。まず、前回の記事で「今後の課題」として挙げたまま放置していた宿題でした。次に、この個人開発は「App Storeリリースフローを学ぶ」ことを一番の目的にしていて、負荷試験の設計・実施・分析もその範囲に入ります。最後に、実際に踏んだ過去の不具合(プッシュ通知の半数失敗、Celeryのfd/接続リークによる監視全滅)はどちらも「繰り返し実行や長時間稼働で初めて顕在化する」種類で、単体テストでは検出できません。段階負荷でも、似た種類の問題が見つかるはずだと考えました。
方針は「staging で段階的に負荷を上げ、最初に劣化する点(膝)を探す。本番には合成負荷をかけない」です。膝の位置に安全係数(0.5〜0.7)を掛けた値を「検証済みの上限」とし、本番の実際の使用量と比較します。
2. stagingは本番と地続き ― 外せない安全装置
MineWatchのstagingは、ingress controller・Kubernetesのノード・PostgreSQLのインスタンスを本番と共有しています。実際に試験の少し前、別件(Jenkinsのビルド)でノードが過負荷になり、stagingのRedisが落ちてアラートが発火したことがありました。その教訓もあって、負荷試験ツールには、設定では外せない安全装置をコードに固定しました。
| 止め金 | 内容 |
|---|---|
| 宛先の固定 | 認証つきのリクエストはstagingのホストにしか送らない。TCPの接続先も、空か private な IP:port だけを許す(トークンを作る前に検証する) |
| Firebaseプロジェクトの固定 | サービスアカウントのproject_idがminewatch-devでなければ止まる。本番の鍵は使えない |
| テストアカウントの接頭辞 | uidは必ずloadtest-で始まる。それ以外のユーザーは作らない・触らない・消さない |
| ガード | 本番の/healthzの異常、ノードのメモリ空き < 500 MiB、負荷 > 3/CPU(2回続けて)、Prometheusに繋がらない、のどれかで自動で止める
|
| 後片付け | 終了時(異常・Ctrl-Cを含む)にloadtest-の全アカウントを削除する。API側の削除が失敗したときは、Firebaseのユーザーを消さずに残す(DBの行が孤児になるのを防ぐ) |
| 待ちの上限 | 外部への待ちには必ず上限を付け、実行全体にも時間制限を持たせる |
宛先の固定は、こういう形でコードに落としています(loadtest/common.pyの実装イメージ)。
def validate_direct_addr(raw: str) -> str:
"""空(Cloudflare経由)か、private な IP:port だけを受け付ける."""
if raw == "":
return raw
host, _, port = raw.partition(":")
allowed = ipaddress.ip_address(host).is_private and 1 <= int(port) <= 65535
if not allowed:
sys.exit(f"STOP: LOADTEST_DIRECT_ADDR={raw!r} must be empty or a private IP:port")
return raw
「本番の鍵に切り替えれば試験対象を本番にできる」「宛先を書き換えれば外部に打てる」を、実行時の判定ではなく、値そのものの検証で塞いでいます。設定ミス1つで本番に負荷がかかる、という事故を構造的に防ぐのが狙いです。
3. 測り方: 「膝」を探して安全係数を掛ける
台数やリクエスト数を段階的に上げ、各ステップを一定時間保持して、劣化の兆候(キューが空にならない、p95が1秒を超える、鮮度が悪化する)が出た段階を「膝」とします。膝の1段階手前までを「正常だった最大」とし、そこに安全係数0.6を掛けた値を「検証済みの上限」にします。これを本番の実際の使用量と比べれば、「上限の何割を使っているか」が分かります。
計測は3つの次元で行いました。監視対象のサーバー数(登録数を段階的に増やす)、APIの同時リクエスト(k6でRPSを上げる)、SSEの同時接続数です。
4. 監視ワーカー: 検査1回のコストは「DB接続を開くこと」だった
4-1. 最初の結果: 700台で息切れ
監視対象のサーバーを段階的に増やし、全部が正常に応答するケースで測ったところ、次のようになりました。
| 台数 | 需要(件/秒) | 処理量(件/秒) | 鮮度 最大 | キューのピーク | 判定 |
|---|---|---|---|---|---|
| 500 | 7.14 | 7.19 | 76秒 | 56 | 正常 |
| 600 | 8.57 | 8.48 | 79秒 | 63 | 正常 |
| 700 | 10.00 | 7.34(73%) | 168秒 | 316 | 飽和 |
600台までは正常、700台でキューが空にならず飽和しました。worker(Celery、concurrency 4、CPUの上限1コア)のCPU使用量は台数にほぼ比例していて、700台で0.97コアと、上限の1.0にほぼ届いていました。
4-2. 内訳を測る: SQLは0.03ms、接続を開くのに14ms
「検査1回のコスト」を手元で計測したところ、直感に反する結果が出ました。
| 測ったもの | CPU |
|---|---|
DB接続を1本開く(asyncpg。SCRAM認証を含む。接続・SELECT 1・切断) |
14.0 ms |
開いている接続でのSELECT 1
|
0.03 ms |
検査1回あたり、SQLの実行そのものは1本0.03msしかかかりません。ところが従来の実装(asyncio.run()でタスクごとに新しいイベントループを作る設計。async SQLAlchemyの接続プールは最初に使ったループに紐づくため、プールを使うと"Future attached to a different loop"で落ちる制約があり、NullPoolで毎回接続を開き直していました)は、記録後の再読み込み(session.refresh)でもう1回SELECTを打つため、検査1回でDB接続を2本開いていました。SQLの本数を減らしても意味がなく、「接続を開く回数」を減らすことが効くという結論です。
4-3. 直した後: 1000台でもまだ正常
対策は2段階です。第1段で、記録後の再読み込みをやめ、連続失敗回数もDBに聞かずに計算するようにしました(接続2本 → 1本)。第2段で、Celeryのprefork子プロセスごとにイベントループを1つだけ持ち続け、小さな接続プールを使い回す実装に変えました。
"""Celery ワーカー用の DB セッション.
プロセスごとに 1 つのイベントループを持ち続け、その上で小さな接続プールを使い回す。
以前は、タスクごとに asyncio.run() で新しいループを作っていたので、プールを使うと
「Future attached to a different loop」で落ち、NullPool(コネクションを保持しない)を
使っていた。その代わり、検査 1 回ごとに DB 接続を開き直すことになり、これが検査の
コストの大半だった。
"""
# 1 プロセスが同時に要る接続は 1 本 (タスクは 1 つずつ)。予備を 1 本足す。
POOL_SIZE = 1
MAX_OVERFLOW = 1
POOL_RECYCLE_SEC = 1800 # 長く使い回した接続を入れ替える間隔
実際のLinuxコンテナ上のCelery(prefork、2プロセス)で確かめた結果です。
変更前(NullPool) |
変更後(プール) | |
|---|---|---|
| workerのCPU / 検査 | 24.5〜24.9 ms | 6.8〜9.5 ms(約62〜72%減) |
| 処理量(2プロセス) | 53.6件/秒 | 107〜136件/秒(約2〜2.5倍) |
stagingで同じ条件で測り直すと、劣化の膝の位置がはっきり動きました。
| 前回 | 今回 | |
|---|---|---|
| 正常だった最大 | 600台 | 1000台以上(1000台でも膝は見つからず、測定はここで打ち切り) |
| 700台 | 飽和(処理量73%、CPU 0.97コア) | 正常(処理量100%、CPU 0.21〜0.24コア) |
| 検査1回のCPU | 約120ms | 15〜22ms(約1/6〜1/8) |
CPUは台数にほぼ比例するので、1コアに届くのは概算2500台前後と見込まれます(推定であり、実測は1000台まで)。
5. API: 「読み取り専用」のはずが、認証のたびにDBへ書いていた
5-1. p50が270msもかかる理由の9割
GET /v2/servers(認証つき、20台のサーバーを返す)をk6で段階的に負荷をかけたところ、低負荷でもp50が約270msかかっていました。
| 目標(req/s) | 達成 | p50 | p95 | apiのCPU | 判定 |
|---|---|---|---|---|---|
| 5 | 5.0 | 272 ms | 309 ms | 0.12 | 正常 |
| 20 | 19.9 | 268 ms | 641 ms | 0.46 | 正常 |
| 40 | 37.7 | 3753 ms | 15114 ms | 0.77 | 飽和 |
低負荷でも270msかかる原因を、staging の api Pod の中で直接切り分けたところ、9割はID tokenの失効チェックでした。
| 検証 | 時間(p50) |
|---|---|
| ID token(失効チェックあり。既定) | 235〜248 ms |
| ID token(失効チェックなし) | 1.0〜1.6 ms |
Firebaseは「アカウントを削除したのにトークンが生きている」事故を防ぐため、認証つきの全リクエストで、失効していないかをGoogleのサーバーに毎回確認する設計を既定にしています。これが、往復のたびに約240msの待ち時間を生んでいました。
5-2. キャッシュを入れて2倍に
失効チェックの結果をuidごとに30秒だけ覚えるキャッシュ(AUTH_REVOKED_CACHE_TTL_SEC)を追加しました。
# 「アカウントを削除したのにトークンが生きている」ほうが問題なので既定は True。
auth_check_revoked: bool = True
# 失効チェックの結果を uid ごとに何秒覚えておくか。0 = 覚えない (毎回確認)。
auth_revoked_cache_ttl_sec: int = 0
30秒に設定して測り直すと、次のように変わりました。
| 対策前 | 対策後 | |
|---|---|---|
| p50(低負荷) | 約270ms | 20〜22ms(約1/12) |
| p95が1秒以内に収まる最大 | 20 req/s | 40 req/s |
「待ち時間はCPUを使わないので、頭打ちのreq/sには効かないはず」と当初は見立てていましたが、これは外れました。頭打ち自体も約2倍に上がったのです。理由は特定できていません(同時に多数のリクエストが待っている状況の負荷を、1回ずつの計測では捉えられていない可能性がある、という仮説だけ残っています)。
代償として、アカウントの無効化・全端末ログアウトの反映が最大30秒遅れます。この個人開発では許容できる範囲と判断し、本番も30秒に設定しました。
5-3. 残りの内訳を測る: _touch_loginが27%
失効チェックを直したあとも、1リクエストあたり約13〜15msのCPUが残っていました。この内訳を、手元でAPIをASGI直接呼び出しして、1つずつ機能を止めて測る方法(アブレーション)で切り分けました。
| 止めたもの | 減った分 | 割合 |
|---|---|---|
_touch_loginの書き込み(UPDATE + COMMIT + 再読み込み) |
0.92 ms | 27% |
| BaseHTTPMiddleware 4段(アクセスログ・メトリクス・セキュリティヘッダ・言語) | 0.65 ms | 19% |
| (床。ORM・シリアライズ・フレームワーク) | 残り | 65% |
_touch_loginという名前の通り、これはログイン時刻を記録する処理です。問題は、読み取り専用のGET /v2/serversを呼ぶだけでも、毎回このUPDATEが走っていたことでした。
"""メール・表示名・最終ログイン時刻を、必要なときだけ Firebase の値で上書きする.
変わっていなければ、書かない。最終ログイン時刻は、前回の記録から
last_login_touch_interval_sec 秒 (既定 10 分) たったときだけ書き直す。以前は
認証のたびに UPDATE + COMMIT + 再読み込みの SELECT を行い、読み取りだけの GET でも
DBの往復が3回増えていた (apiのCPUの約27%)。
"""
last_login_atの用途はadminの「ログイン実績」表示とGET /meの表示だけなので、分単位の粒度で十分でした。プロフィール(メール・表示名)が変わっていない限り書かない、10分に1回だけ書く、に変えました。もう1つのBaseHTTPMiddleware(アクセスログ・メトリクス・セキュリティヘッダ・言語判定の4段)は、リクエストごとにタスクとストリームを作るコストがあったため、純粋なASGIミドルウェアに書き直しました。
両方の対策後、staging で測り直した結果です。
| 前回(失効チェック対策後) | 今回 | |
|---|---|---|
| p95が1秒以内に収まる最大 | 40 req/s | 60 req/s(80で超過) |
| 1リクエストあたりのCPU | 約13〜15 ms | 約9〜11 ms(約30%減) |
「読み取り専用のはずのAPIが実は毎回書き込んでいた」というのは、書いた本人(自分)も見返して初めて気づいた類の問題でした。負荷をかけて初めて、CPUという形で存在感を持って現れてきます。
6. SSE: リアルタイム配信が実は何も届いていなかった
6-1. Ingressがまるごとバッファしていた
サーバー状態のリアルタイム配信(SSE)を、経路ごとに1接続だけ試したところ、根本的な問題が見つかりました。
| 経路 | ハートビート(15秒ごと) |
|---|---|
| apiに直接(クラスタ内) | 15.4秒に届く |
| stagingのnginx経由(クラスタ内) | 15.4秒に届く |
| Ingress経由(NodePort・Cloudflare経由とも) | 届かない |
原因は、Ingress(NGINX Ingress Controller)がproxy_buffering on;のままだったことです。背後のnginxにはSSE用のproxy_buffering off設定がありましたが、それはIngressの1段後ろにあり、Ingress自体のバッファには効きません。段階負荷を測るはずが、測る前に「そもそも届いていない」という土台の問題にぶつかりました。
# 背後の nginx の SSE 用 location(proxy_buffering off)は、Ingress の 1 段後ろで、
# Ingress のバッファには効かない。
nginx.org/proxy-buffering: "False"
この1行をIngressの注釈に足すだけで解決しましたが、気づかなければ「Web側の実装ミスだろう」と見当違いの調査を続けていたと思います。
6-2. 直したら別の地雷: DB接続を握り続けて15接続で全滅
Ingressの問題を直して段階負荷を再開しようとしたところ、2つ目の問題が見つかりました。SSEのハンドラが、ユーザーを特定するためのDB依存を、ストリームが終わるまで閉じない実装だったのです。
async def get_stream_user_id(
session: SessionDep,
identity: CurrentIdentityDep,
credentials: BearerCredentialsDep,
) -> int:
"""ストリームを張るユーザーの id を返し、DB の接続はここで手放す.
ユーザーの特定にだけDBを使う。ストリームの間はDB接続を持たない。
なぜここで閉じるか: yield を使う依存は、レスポンス = ストリームが終わるまで
閉じられないため、このままだとSSEの1接続ごとに、ストリームが続く間ずっと
DB接続が1本塞がる。api 1 Podの接続プール(5 + オーバーフロー10 = 15本)が
SSE 15接続で埋まり、SSE以外の全リクエストも500になる。
"""
実際に10接続を保持したところidle in transactionの接続が11本あり、25接続を試すと15本しか成立せず、残りはプール待ちの30秒でタイムアウトしてHTTP 500になりました。プールが埋まると、SSEと無関係な通常のAPIリクエストまで500になります。 staging では実際にadmin(内部APIを叩く画面)がこれでCrashLoopBackOffになりました。
修正は、ユーザーの特定が終わったらすぐにDBセッションを閉じ、ストリームの間はDB接続を持たない形にすることでした。修正後は、20接続・40接続を保持しても、失敗0・切断0で、保持中のDB接続はプールの通常分(5本)のままでした。
「リアルタイム機能が届いていない」ことと「リアルタイム機能が他の機能を巻き込んで落とす」ことの2つが、段階負荷をかける前段階で見つかったことになります。
7. 負荷試験ツール自身が事故を起こした話
最初の版のSSE試験ツールが、最初のステップで固まり、約2時間40分、stagingのDB接続15本を握ったままになりました。その間、stagingのapiは500を返し続け、adminはCrashLoopBackOffになりました。幸い本番は無傷でした(/healthzは200のまま、DBのロールも本番用とは別で、stagingのロールの接続数は上限40に収まっていました)。
原因は、レスポンスのヘッダの到着を無期限に待つ設定(read=None)と、実行全体の時間制限が無かったことです。後片付けの処理は実行が終わってから走る作りだったので、固まると後片付けも走りませんでした。
前回の記事で、「Celeryのworkerが接続をリークして監視が全滅した」という過去の不具合を紹介しましたが、今回は守るためのツール自身が同じ構造(リソースを握ったまま止まらない)の罠を踏んだことになります。対策として、SSEの読み取りに45秒の上限、実行全体の時間制限、時間切れ時の全接続の強制キャンセルを入れました。自動で走らせるツールは、待ちと実行全体の両方に上限を持たせる、というのが今回の一番実務的な教訓です。
8. 「膝」と本番の使用率を並べる
見つかった膝に安全係数0.6を掛け、本番の実際の使用量(2026-09-26時点、ユーザー8・サーバー4台)と比べました。
| 次元 | stagingで正常だった最大 | 安全係数0.6 | 本番の現在 | 使用率 |
|---|---|---|---|---|
| 監視対象のサーバー(現実的な混合: 正常90%・拒否5%・応答なし5%) | 300台 | 約180台 | 4台 | 約2% |
| 同(最悪ケース: 全部が応答なし) | 45台 | 約27台 | 4台 | 約15% |
| APIのリクエスト(対策後) | 60 req/s / Pod | 36 req/s / Pod | 未計測 | - |
| SSEの同時接続(修正後、上限は未測定) | 40接続以上 / Pod | - | 未計測 | - |
現在の使用率はどれも低く、この規模では急いで手を入れる必要はありません。ただし、同じ台数でも、落ちているサーバーの割合で限界が1桁変わるという点は覚えておく必要があります。全部正常なら1000台以上でも余裕がありますが、応答のないサーバーが混ざると45台で飽和します。監視対象が増えるとしたら、「何台まで」だけでなく「どれくらいが不調になり得るか」も一緒に見る必要があります。
9. まだ終わっていないこと
- APIとSSEの本番実測がまだ無い。本番のメトリクス収集(PodMonitor)自体は直近のリリースで有効になりましたが、staging で見つけた上限と実際に比較する作業はまだ手つかずです。
- 失効チェックのキャッシュが切れた瞬間、同じuidの並行リクエストが全部Googleに往復していないか、という仮説が残っています(single-flightが無い)。この試験は1ユーザーにレートが集中する最悪の条件だったため、本番(8ユーザー・低いレート)では起きにくいと見ていますが、確認はしていません。
- 監視ワーカーのCPUの上限を上げた場合の検証(1コア → 2コアで限界がどう動くか)は推定のままです。
- 自動化は一部だけ進みました。PRレビュー時に「検査1回あたりのDB往復の数を数える単体テスト」と、「負荷への影響」のレビューチェック項目は、どちらも実装・マージが済みました。夜間・週次の定期実行はまだ手を付けていません。前回の記事で書いた「リリース前に回す層に置くのが妥当」という方針どおり、まずはリリース前の任意ゲートとして手順書に組み込みました。
まとめ
- 「読み取り専用」に見えるAPIが実は書き込んでいる、DB接続を毎回開き直している、リアルタイム配信がIngressの設定で丸ごと止まっている ― どれも、コードを読むだけでは気づきにくく、負荷をかけて初めて存在感を持って現れました。
- ボトルネックの内訳は、勘や理論で決めつけず、実測(アブレーション、Pod内での直接計測)で切り分けました。「待ち時間はCPUを使わないはず」という見立てが外れた、という失敗も含めて記録しています。
- stagingは本番と地続きなので、負荷試験そのものが事故の原因にならないよう、外せない安全装置と、待ち・実行全体の時間制限が必須でした。ツール自身の不具合で、実際に2時間40分の“自傷”を起こしました。
- 8ユーザーの個人開発の規模では、今回見つかった上限に対する使用率はどれも低く、緊急性はありません。それでも、「膝」がどこにあるかを知っていることと、知らないことの差は大きいと感じています。
個人開発の環境での構成なので、そのまま組織に持ち込む場合は、共有インフラへの影響範囲や、負荷試験自体の承認プロセスを先に確認してください。
JQITのエンジニアの95%以上は未経験からの採用です。
よければコーポレートサイトにも遊びに来てください。
未経験から学べます!一緒に挑戦していきましょう![]()
noteやXもやってます↓