0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

【障害調査】AIにログを丸投げするより、人が5分切り分けてから渡した方が速かった

0
Posted at

AIと人の障害調査比較-clean.png

わざと社内検証環境で障害を起こすようにしてもらいました。

ログにはこう出ている。

HikariPool-1 - Connection is not available,
request timed out after 30000ms.

さて、どう調べるか。

  • 経験のあるエンジニアが普通に調査する
  • とりあえずAIにログを全部渡す
  • AIで仮説を出してから、人が調べる
  • 人が状況を整理してから、AIを使う

結局、どれが一番速く「本当の原因」までたどり着けるのか。

今回は、同じ障害を使って進め方を変え、原因特定までのプロセスを比較してみました。

先に結果を書くと、

最も速かったのは「人が最初に切り分ける → AIに考えさせる → 人が検証する」でした。

AIに全部任せるでもない。

人間だけで頑張るでもない。

ポイントは、どこをAIに渡すかでした。

今回用意した障害

検証用に、Web APIで次の障害を再現しました。

環境は以下です。

Java 21
Spring Boot 3.x
MySQL 8
HikariCP

注文検索APIがあります。

GET /api/orders/search

普段は正常なのですが、ある程度データ件数が多くなるとレスポンスが急激に悪化。

最終的には500エラーになります。

ログを見ると、

HikariPool-1 - Connection is not available,
request timed out after 30000ms.

さらに、

SQLTransientConnectionException

も発生。

CPU使用率はそれほど高くない。

メモリにも余裕がある。

ところがDB接続だけが枯渇していきます。

一見すると「DBコネクションプール不足」に見える

このログだけ見たら、最初に疑いたくなるのはこれです。

maximumPoolSize が小さい?

あるいは、

DBが遅い?

または、

コネクションリーク?

どれもありそうです。

そしてここが、今回の障害調査で面白かったところです。

エラーメッセージが示している場所と、障害を作っている原因が違いました。

実際の原因

問題になっていたコードをかなり単純化すると、こんな状態でした。

List<Order> orders = orderRepository.search(condition);

for (Order order : orders) {
    List<OrderDetail> details =
        orderDetailRepository.findByOrderId(order.getId());

    order.setDetails(details);
}

検索結果が10件なら、大きな問題にはなりません。

しかし1,000件返ってくれば、

注文検索       1回
明細検索   1,000回
----------------
合計       1,001回

SQLが発行されます。

いわゆるN+1問題です。

アクセスが重なると大量のSQLが発行され、DB接続が長時間占有される。

その結果、

HikariPool-1 - Connection is not available

が発生していました。

つまり、

表面上の症状
↓
DBコネクション不足

本当の原因
↓
大量のSQL発行
↓
コネクション占有
↓
プール枯渇

という構造です。

では、4つの方法で調べてみる

今回比較したのは次の4パターンです。

方法 進め方
① 人だけ ログ、DB、コード、変更履歴を順番に調査
② AIだけ ログを中心にAIへ調査を依頼
③ AI → 人 最初にAIへ仮説を出させ、人が検証
④ 人 → AI → 人 人が事実を整理 → AIに仮説生成 → 人が確認

「原因らしきものを出す」ではなく、

実際に原因を特定して説明できる状態

までをゴールとしました。

① 人だけで障害調査

まずは普通に調べます。

ログを見る。

Connection is not available

DBの状況を見る。

コネクション数を見る。

スロークエリを見る。

再現させる。

アクセスログを見る。

直近の変更を見る。

SQLログを出す。

ここまで調べたところで違和感がありました。

同じようなSELECTが大量に出ている

コードを見る。

for (Order order : orders) {
    orderDetailRepository.findByOrderId(order.getId());
}

発見。

N+1でした。

結果

原因特定:約42分

確実ではあります。

ただ、候補を一つずつ潰しているので、それなりに時間がかかりました。

② ログをそのままAIに渡す

次はAIです。

最初は、あえて情報をあまり整理せずに渡しました。

Spring Bootのシステムで以下のエラーが発生しています。

HikariPool-1 - Connection is not available,
request timed out after 30000ms.

SQLTransientConnectionException

考えられる原因と確認方法を教えてください。

AIからは、かなり多くの候補が返ってきました。

例えば、

・maximumPoolSize不足
・DB処理の長時間化
・コネクションリーク
・トランザクション長期化
・DB負荷
・ネットワーク遅延
・アクセス急増

どれも間違いではありません。

でも困る。

候補が多すぎる。

そして最初のほうに、

maximumPoolSizeを増やして確認してください

という方向も出てきました。

ここで設定値を変更すると、一時的に症状が改善する可能性があります。

しかしN+1は残ったままです。

むしろ危ない。

AIは「原因候補」を出すのは速い

これはものすごく速いです。

数秒です。

ただし、

それが今回の障害の原因なのか

は別問題でした。

結局、

どの条件で発生する?
いつから?
何が変わった?
SQLは何回実行されている?

を人間が調べる必要があります。

結果

有力候補提示:数十秒
根本原因特定:約31分

AIの回答は速い。

でも、障害調査そのものが終わるわけではありません。

③ AIに仮説を作らせてから、人が調べる

次は、最初からAIに調査方針まで考えてもらいます。

以下の障害について、
可能性が高い順に原因仮説を整理してください。

また、それぞれを最短で切り分けるための
確認方法も提示してください。

・Spring Boot
・MySQL
・HikariCP
・一定件数以上の検索で発生
・Connection is not available
・CPU、メモリには余裕あり

ここまで情報を増やすと回答はかなり良くなりました。

AIから、

1. クエリ実行時間の増大
2. N+1などによるSQL発行数増加
3. 長時間トランザクション
4. Connection Leak
5. Pool Size不足

という形で整理されました。

お。

N+1がかなり上に来ました。

そこでSQLログを確認。

大量のSELECTを発見。

コードを確認。

原因特定。

結果

原因特定:約23分

かなり速くなりました。

④ 人が最初の5〜10分だけ調べてからAIを使う

最後の方法です。

いきなりAIには聞きません。

まず人間が、

「事実だけ」を集めます。

今回整理したのはこれだけでした。

【現象】
注文検索APIがタイムアウトする

【発生条件】
検索結果が数百件を超えると発生しやすい

【エラー】
HikariPool Connection Timeout

【CPU】
正常

【メモリ】
正常

【DB】
Connection使用数が急増

【SQL】
同じ形式のSELECTが大量発行されている

【変更】
直近のリリースで注文詳細取得処理を追加

ここまで整理してAIへ。

AIへの入力

Spring Boot + MySQLの障害調査です。

以下は確認済みの事実です。

・注文検索APIで発生
・検索結果件数が増えるほど発生しやすい
・HikariCPのConnection Timeoutが発生
・CPU、メモリには余裕あり
・API実行中にDB Connection使用数が急増
・同じ形式のSELECT文が大量に発行されている
・直近リリースで注文詳細取得処理を追加

この情報だけから、
可能性の高い原因を3つまでに絞ってください。

また、
「追加で何を確認すれば原因を確定できるか」
も提示してください。

設定変更などの対処法ではなく、
根本原因の特定を優先してください。

すると、かなりストレートに、

第一候補:
注文一覧取得後、注文単位で詳細SQLを実行している
N+1クエリの可能性

が出てきました。

さらに、

・1リクエストあたりのSQL発行数
・検索結果件数とSQL発行数の関係
・直近追加された詳細取得処理

を確認するよう提案。

コードを見る。

for (Order order : orders) {
    orderDetailRepository.findByOrderId(order.getId());
}

ほぼ一発でした。

結果

原因特定:約16分

今回もっとも速い結果になりました。

比較結果

まとめるとこうなりました。

調査方法 原因特定まで 特徴
人だけ 約42分 確実だが探索範囲が広い
AIだけ 約31分 仮説は速いが候補が多い
AI → 人 約23分 調査開始は速い
人 → AI → 人 約16分 最も速く根本原因へ到達

もちろん障害内容やエンジニアの経験値によって結果は変わります。

ただ、今回かなりはっきりしたことがあります。

AIに一番最初から「答え」を聞くと、意外と遅い

AIを使うとき、ついやりがちなのがこれです。

このエラーの原因を教えて。

でもAIからすると情報が足りません。

当然、回答はこうなります。

可能性①
可能性②
可能性③
可能性④
可能性⑤
……

正しい。

でも、

障害調査では「正しい候補をたくさん出すこと」が目的ではありません。

必要なのは、

今回の原因を最短で1つに絞ること。

です。

AIに渡す前に、人間がやるべきこと

今回一番効いたのは、専門知識を使った難しい解析ではありませんでした。

次の情報を整理したことです。

いつ起きる?
何をすると起きる?
どこまでは正常?
どこから異常?
最近何が変わった?
何が増えた?
何は正常?

障害調査の基本そのものです。

例えば、

Connection Timeoutが出ています

だけでは情報量が少ない。

しかし、

100件では発生しない
500件から遅くなる
1000件ではほぼ発生する
SQL実行回数も件数に比例して増える

となれば、一気に原因へ近づきます。

「ログ全部貼る」がAI活用ではない

AIを使っていると、

ログを全部貼る
↓
原因を聞く

をやりたくなります。

しかし実際の障害調査では、それよりも、

人
↓
事実を整理する

AI
↓
仮説を圧縮する

人
↓
事実で検証する

のほうが強い。

特に大事なのが最後です。

AIの回答を「正解」にしてはいけない

例えば今回、

AIがこう回答したとします。

N+1問題の可能性が高いです。

そこで、

なるほど、N+1か。

で終わったら障害調査ではありません。

確認する。

例えばSQL発行回数。

検索結果 10件
→ SQL 11回

検索結果 100件
→ SQL 101回

検索結果 1000件
→ SQL 1001回

これならかなり強い証拠になります。

さらにコードを見る。

for (Order order : orders) {
    repository.findByOrderId(order.getId());
}

そして修正する。

例えばJOINや一括取得へ変更。

List<Long> orderIds =
    orders.stream()
          .map(Order::getId)
          .toList();

List<OrderDetail> details =
    orderDetailRepository.findByOrderIds(orderIds);

再計測する。

SQL 1001回
↓
SQL 2回

負荷試験する。

再現しない。

ここまでやって、

「原因だった」と言えます。

AIが原因を決めるのではありません。

事実が原因を決めます。

今回一番重要だったのは「AIへの質問力」でもなかった

個人的に一番重要だと感じたのはここです。

AI活用というと、

プロンプトを上手に書く

ことに注目されがちです。

もちろん重要です。

でも障害調査では、それ以前に、

何が分かっていて、何が分かっていないのかを分けられること

のほうが圧倒的に重要です。

AIは、この差を勝手には埋めてくれません。

障害調査で使えた「5分間の切り分け」

今回のやり方を実務向けにすると、かなりシンプルです。

障害が起きたら、いきなりAIに投げず、まずこの7つを埋める。

■ 1. 何が起きている?
500エラー、遅延、データ不整合など

■ 2. いつから?
リリース後、特定日時からなど

■ 3. 何をすると起きる?
データ量、ユーザー、操作、時間帯

■ 4. 何なら起きない?
正常ケースとの違い

■ 5. どこまで正常?
AP、DB、外部API、NWなど

■ 6. 最近何が変わった?
ソース、設定、DB、インフラ、データ

■ 7. 数字で何が変化している?
CPU、メモリ、SQL数、Connection数、レスポンス時間

これをAIに渡します。

障害調査用プロンプト

実際には、次のテンプレートだけでもかなり使えます。

システム障害を調査しています。

以下は確認済みの「事実」です。

【現象】
XXX

【発生条件】
XXX

【発生しない条件】
XXX

【エラー】
XXX

【正常なもの】
XXX

【異常なもの】
XXX

【直近の変更】
XXX

原因候補を可能性の高い順に3つまで出してください。

それぞれについて、
・その原因だと考える理由
・原因を否定するための確認方法
・原因を確定するための確認方法
を提示してください。

まだ根拠が足りないものは断定しないでください。

設定変更や再起動などの対症療法より、
根本原因の特定を優先してください。

ポイントは、

原因を教えて

ではなく、

どうすれば、その仮説を否定または確定できる?

まで聞くことです。

これだけでAIがかなり「調査員」に近づきます。

AI時代に障害調査ができるSEとは

今回試してみて感じたのは、

AIが入っても、障害調査の基本は変わっていない

ということです。

むしろ重要性が増している気さえします。

事実を見る
↓
切り分ける
↓
仮説を立てる
↓
検証する
↓
原因を特定する

この途中にAIが入っただけです。

AIは、

仮説を大量に出す
見落としを指摘する
コードを読む
ログを読む
調査観点を出す

ことが非常に得意です。

一方、人間には、

何が重要な事実なのか判断する
本番環境の状況を理解する
情報の正しさを判断する
仮説を実環境で検証する
影響範囲を判断する
最終的な責任を持つ

という仕事が残ります。

「AIが障害を調べる」のではない

今回の結果を一言でまとめるなら、

AIが障害を調べるのではなく、人がAIを使って調査範囲を高速に狭める。

ということでした。

AI単体が最強だったわけではありません。

人間だけが最強でもありません。

人が観察する
↓
AIに考えさせる
↓
人が確かめる

この往復が一番速かった。

個人的には、AI時代のエンジニアリングで重要なのは、

「自分で全部答えを出せること」から「最短で正しい答えに到達できること」へ変わっていく

のではないかと思っています。

障害調査は、その変化がとても分かりやすく表れる仕事の一つなのかもしれません。


エスプリフォートでは、AIを使って終わりではなく、
AIをどう実務の成果につなげるかを考えています。

技術そのものだけではなく、AIと人それぞれの強みを組み合わせ、
顧客価値につなげるエンジニアリングをこれからも探っていきます。

0
1
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
0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?