50
52

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

個人開発のMinecraft監視アプリに負荷試験をしてみた ― 読み取り専用のAPIが、実は毎回DBへ書き込んでいた

50
Last updated at Posted at 2026-09-28

個人開発の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%以上は未経験からの採用です。
よければコーポレートサイトにも遊びに来てください。

:sparkles:未経験から学べます!一緒に挑戦していきましょう:sparkles:

noteやXもやってます↓


50
52
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
50
52

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?