Skip to content

3つの計測を行き来しよう

ここまでで、3本の懐中電灯が揃いました。

  • slow query logは、SQLの時間・回数・調べた行数を見せる
  • access logは、URLごとの回数・待ち時間・転送量を見せる
  • pprofは、Goの関数ごとのCPU時間を見せる

ここからは「次は必ずこのツール」と決まっていません。アクセスログで回数の多いURLを見つけ、pprofで中へ入り、SQLが原因ならスロークエリログへ戻る。この往復をAgentに任せつつ、人間は判断の筋道を確認します。

自走を頼むプロンプト

text
ここからはslow query log、access log、pprofを行き来し、計測→仮説→改善→再計測を自走してください。

- 解説記事や既存の解答は見ず、公式マニュアル、実装、実測だけを使う
- 毎回、一番大きい数字だけでなく、回数・合計時間・遅い側の値も比べる
- ベンチは1分かかるので、同じ原因の変更はまとめてよい
- 大きな構造変更も、仕様と計測から説明できるなら試してよい
- 変更前に仮説を一文で残し、変更後は必ずベンチを実行する
- pass、deduction、timeout、HTTP 5xx、serviceの状態も確認する
- スコアが大幅に落ちた変更、意味が変わった変更、説明できない変更は戻す
- 失敗した実験も、観測・結果・戻した理由を短く履歴へ残す
- 最後は再起動し、serviceの自動復帰と再起動後のベンチを確認する

約1時間を目安に、残り時間とベンチ1回の時間を見ながら進めてください。
各loopの終わりに、次に見る数字を人間へ短く説明してください。
ここからはslow query log、access log、pprofを行き来し、計測→仮説→改善→再計測を自走してください。

- 解説記事や既存の解答は見ず、公式マニュアル、実装、実測だけを使う
- 毎回、一番大きい数字だけでなく、回数・合計時間・遅い側の値も比べる
- ベンチは1分かかるので、同じ原因の変更はまとめてよい
- 大きな構造変更も、仕様と計測から説明できるなら試してよい
- 変更前に仮説を一文で残し、変更後は必ずベンチを実行する
- pass、deduction、timeout、HTTP 5xx、serviceの状態も確認する
- スコアが大幅に落ちた変更、意味が変わった変更、説明できない変更は戻す
- 失敗した実験も、観測・結果・戻した理由を短く履歴へ残す
- 最後は再起動し、serviceの自動復帰と再起動後のベンチを確認する

約1時間を目安に、残り時間とベンチ1回の時間を見ながら進めてください。
各loopの終わりに、次に見る数字を人間へ短く説明してください。

「速そう」でも戻した2つの実験

自走中、pprofとスローログから次の候補が見えました。

1つ目はsessionの確認です。署名済みcookieの復号と「このuserはいるか」というSQLが何千回も呼ばれていました。cookieとuser IDをmemoryへ覚える実験をしましたが、スコアは25,425から18,940へ低下。passはしても、1分ベンチの揺れで片づけにくい差なので戻しました。

2つ目はISU一覧のN+1です。一覧を取ったあと、ISU1台ごとに最新状態を取っていました。最新状態cacheを広げ、1回のJOINにする実験では、最初にSQLの予約語を引用し忘れて状態更新が500になりました。修正後は21,254passしましたが、直前の最高点を下回ったため、この構造変更も採用しませんでした。

失敗は「Agentがだめだった」で終わりません。

  • ローカルで分かるコンパイルエラーは、デプロイ前のbuildで止める
  • SQLは実際のDBで実行しないと分からない失敗がある
  • passだけでなく、endpoint別のstatusと意味を確認する
  • 改善を小さなcommitに分けておくと、安全な地点へ戻りやすい

この4つが、次のloopを速くします。

最高点より、正しく動く採用版

EC2を再起動したあと、nginx・MariaDB・Goアプリ・pprofが自動で復帰しました。その状態のベンチでは、一時25,841が出ました。

しかしアクセスログを確認すると、状態POSTの約10%が500でした。履歴の保存は成功していたためスコアは出ますが、最新状態cacheの更新SQLが予約語の引用漏れで失敗していました。既知の500を残した最高点は採用できません。

SQLを直した最終ベンチは次の結果です。

項目最終結果
スコア20,306
passyes
deduction0
timeout2
HTTP 5xx0件
最新状態cacheの時刻不一致0件
負荷中に増えた利用者33人

最新状態が正しく更新されたことでサービス評価が上がり、ベンチマーカーが利用者を増やしたため、壊れていた最高点とは負荷条件も変わりました。ここでは20,306を採用します。

今回の1時間を振り返る

初期1,284から、最終採用版は20,306になりました。約15.8倍です。途中の最大値を競うだけなら別の数字を選べますが、再起動でき、500がなく、cacheと元データが一致するところまでが今回のゴールです。

大きな節目スコア次を決めた観測
初期状態1,284timeout 386。原因はまだ不明
slow query 1回目7,125trend 68秒、一覧から約50万行
slow query 2回目18,572SQLの大きな山が消えた
nginxで静的配信19,628icon 117MB
icon cache20,390pprofでログとJSON整形が上位
pprof改善24,516trendが2.42秒
正しさ確認済み最終版20,3065xx 0、cache不一致0

AI Agentは、大量のコードを一気に書けます。だからこそ、人間の役目は小さくなりません。どの数字を見たか、変更が仕様を守っているか、悪化したら戻せるか。そこを一緒に考えると、Agentはとても強いチームメンバーになります。

そして何より、スコアが跳ねる瞬間はやっぱり楽しいです。次は自分たちの環境で、最初の一本の懐中電灯をつけてみましょう。