ログ分析は、AIに任せる時代になりました ― Dr.Sum・DataSpider・MotionBoardのログを1本の時間軸に載せる

〜 目で追って「点」を確認する読み方から、全体像を見てから原因へ降りる読み方へ 〜

支援先の分析基盤で、Dr.SumサーバーのCPUが高止まりし、DataSpiderのデータ連携がエラーになる、という相談をいただきました。Dr.Sum（集計データベース）、DataSpider（データ連携）、MotionBoard（可視化）の3製品が動いている環境です。

結果として、原因は特定できました。分析そのものにかかった時間は数時間です。日数がかかったのは3製品ぶんのログを揃えるまでの段取りで、読んで突き合わせて絵にする工程は数時間で終わっています。

お伝えしたいのは調査の腕前の話ではありません。ログの読み方そのものが、AIと組み合わせることで変わったという話です。数年前の私なら、同じログを渡されても同じ結論には辿り着けませんでした。読める量が足りないからです。

この記事は、同じ3製品をお使いの方がそのまま真似できる形でまとめました。どのログをどこから取るか、何をキーに結ぶか、どんな図を作るか、AIにどう指示するか。順に置いていきます。

実際の調査手順・つまずいた点は、体験談として別にまとめています。 👉 具体版（体験談）：Dr.Sum・DataSpider・MotionBoardのログを1本の時間軸に載せたら、数時間で原因が出た話

1. これまでのログ分析は「目で追う」作業でした

ログ調査が大変なのは、書いてある内容が難しいからではありません。量が人間の処理能力を超えているからです。

• 数十万行のログを全部読むことはできません。だから「当たりをつけて抽出する」ところから始まります
• 抽出条件を決められるのは、すでに原因の見当がついているときだけ。外れれば、条件を変えて振り出しに戻ります
• 製品をまたぐとさらに苦しくなります。Dr.Sum、DataSpider、MotionBoardはログの形式も時刻の粒度も別々なので、どの製品が何時何分に何をしていたかを人が手で突き合わせることになります
• そうして読めるのは、疑ったところの前後だけ。つまり「点の確認」です

そして一番の壁がこれです。全体としてどう流れているのかを把握することは、実質的に不可能でした。

「朝いちばんにDataSpiderのジョブが何本走っていて、どれがどこまで居座り、そこにMotionBoardからの照会がどう重なっているのか」——この絵を人の手で描こうとすると、それ自体が何日もかかります。だから現場では、絵を描かずに経験で推測して、対策を打って、様子を見る、という進め方になります。

今回の相談も、その状態から始まりました。すでに「朝のDataSpider連携を後ろの時間帯へずらす」手当てが打たれていて、それでも症状が消えていませんでした。

2. AIと組み合わせると、順番が逆になります

(1) 抜き取らずに全量を読む — 数十万行を分単位に集約して、指標ごとの最大値まで出す。人がやると何日もかかりますが、AIなら数分です。

(2) 複数製品のログを、1本の時間軸に並べる — これが一番大きい変化でした。詳細は次章に書きます。

(3) 全体傾向が一枚の絵になる — 開始〜終了の帯を並べたガントチャート、分単位の負荷推移、製品間の連動。これまで実質不可能だった全体像の把握が、ここで手に入ります。

(4) その絵から、詳細の原因まで降りられる — 気になった時間帯を指せば、そこで動いていた処理の1ステップ単位の所要時間、失敗した1件のエラー本文まで降りていけます。全体傾向の可視化と原因の特定が地続きになる——ここが決定的でした。

つまり、「推測して確認する」から「全体像を見てから原因へ降りる」へ、順番が逆になったわけです。

3. 【実践】3製品のログは、どこからまとめて取るか

ここが一番地味で、一番効きます。管理画面から1本ずつダウンロードしていると、それだけで数日かかります。まとめて取れる場所を先に押さえると、回収が一度で済みます。

CPUの実測は製品側ではなくOS側にあります。ここを忘れると「重い」の裏付けが取れません。また、DataSpiderと併用でタスクスケジューラからバッチが動いている環境は多いので、製品ログだけ集めると片目をふさいだ状態になります。

4. 【実践】結合キーは「アクセスID」＝Dr.Sumの「要求識別子」

3製品を1本の時間軸に載せる鍵は、共通して振られているIDです。MotionBoardのパフォーマンスログ・操作ログに出るアクセスIDと、Dr.Sum側の「要求識別子」は同じ番号なので、ここで突き合わせられます。DataSpiderとタスクスケジューラは時刻で重ねます。

これで「誰の操作が、どの製品を経由して、どのクエリを呼び、何秒かかったか」が横並びになります。私は別案件で作った突き合わせ用のスクリプトをそのまま流用し、そこにタスクスケジューラを重ねて4層にしました。

人手なら、製品ごとにログを開いて時刻を目で照合していく作業です。AIには、突き合わせの規則を伝えるだけで済みます。

5. 【実践】作った図は4枚

(1) 分単位に集約して、上端で見る

Dr.Sumのモニターログを分単位にまとめ、CPUと同時リクエスト数を重ねます。私は最初、平均値を見て「接続枠は足りている」と判断しました。これが誤りでした。最大値で見ると、上限にぴったり張り付いていたのです。

混雑を測るなら平均ではなく上端を見る。落ちるのは張り付いた一瞬です。

(2) 起動時刻ではなく「占有時間の帯」で並べる

DataSpiderのスケジュール一覧を見ても、犯人は写っていません。実際の正体は、ずっと早い時刻に起動して1時間以上走り続け、ちょうど苦しい時間帯に後半を迎えていた長時間ジョブでした。

一覧表は点、負荷は線。後ろへずらす手当てが効かなかった理由も、これで説明できます。ずらした先にも、まだ走り続けている帯があったのです。

(3) 物差しを1本決めて、混雑計にする

混雑そのものを測るセンサーはありません。そこで、すべてのジョブが必ず通る同一の軽い処理（DataSpiderが実行ログを1件書き込む処理）の所要時間を時系列に並べました。

ふだんは1秒未満のものが始業後のわずかな時間で数秒まで伸び、そのあと回復していく。混雑の立ち上がりと収束が、秒数のグラフとして見えました。しかもその時間帯、DataSpiderの大量取込はすでに終わっていました。残るのは、始業直後にMotionBoardを開く人の動きです。

(4) 症状を分けて、打ち手の副作用を並べる

絵が揃った時点で、症状が2種類に分かれました。

厄介なのは、打ち手が互いを悪くする関係にあることです。次章の仕様がその理由です。

6. 知っておくと効くDr.Sumの仕様

異常終了したジョブのログは、全件が同じエラーでした。

DWException: リクエスト数の上限を超えました。
    at ...createLicenceQueue(...)

createLicenceQueue で失敗しています。処理が重くて時間切れになったのではなく、接続の受付で弾かれていた。ここからマニュアルを読み直して、次の4点を押さえました。

• ［最大同時リクエスト数］はライセンスではなく、サーバーの設定値です。［サーバーの設定］－［制限］タブにあり、設定範囲と初期値がマニュアルに明記されています。今回の環境は初期値のまま、キュー管理の項目もすべて初期状態でした
• 処理の種類で扱いが違います。集計（OLAP）と同期処理は［最大同時実行数］で絞れて、超えた分は待ちキューで待機します（CPUを使いません）。ところがSQL実行は絞れず、「同時リクエスト数に空きがある限り実行される」。埋まっていればエラーになります
• MotionBoardの検索系SQLは、キューの優先度を設定できず最優先で走ります。つまり朝の照会が枠を食い尽くし、DataSpiderのログ書き込みSQLが弾かれる、という筋書きが成立します
• インポート処理は、あるバージョン以降ライセンス枠を消費しません（Ver.4.2.00.0003以降の仕様変更）。実際、取込自体は成功し、その前後のSQLだけが落ちていたので整合します

だから「上限を上げる」は最後の手段になります。上げればエラーは止まりますが、絞りの効かないSQLが同時に増えてCPU負荷はむしろ上がる。先に同時実行そのものを減らすほうが順番として正しい、という結論になりました。

もうひとつ実務的に効いたのが、異常終了の中身の内訳です。失敗のほとんどが業務データの処理ではなく「ジョブの実行ログをDr.Sumに書き込む」ところで起きていました。本体の取込を終えたあと「正常終了しました」と記録する最後の一行で失敗し、異常終了扱いになっていたものもあります。ログ書き込みにリトライを入れるだけで、業務影響のない異常終了は一覧から消えます。

7. そのままAIに渡せる指示文

私が実際に出した指示です。特別な書き方はしていません。

① 全量を集約して上端で見る

このDr.Sumのデータベースモニターログを分単位に集約して、
指標ごとに平均と最大を出して。
最大が上限に触れている指標があれば、到達回数も数えて。

② 占有時間の帯にする

DataSpiderの実行ログから、ステップ別の開始・終了時刻を全件CSVにして。
3分以上かかっている処理だけガントチャートにして、
同じ時間帯に並走しているジョブが分かるようにして。

③ 3製品を1本の時間軸に結ぶ

DataSpiderの実行ログ、Dr.SumのSQL・OLAPログ、MotionBoardの操作ログを、
アクセスID（Dr.Sumでは「要求識別子」）で突き合わせて1本の時間表にして。
タスクスケジューラの実行時刻も時刻で重ねて、4層のガントチャートにして。

④ 混雑計を作る

全ジョブが必ず通る「実行ログを1件書き込む」処理だけを抜き出して、
所要時間を時系列に並べて。伸びはじめた時刻と、戻った時刻を教えて。

⑤ 落ち方で分類する

異常終了した回のログを読んで、どのステップで落ちたかを一覧にして。
業務データの処理で落ちたものと、実行ログの書き込みで落ちたものを分けて。

図（ガントや推移グラフ）は、単一のHTMLとして書き出してもらうと、そのまま報告資料に貼れます。

8. 人の仕事は「何を疑うか」に移りました

今回、私が持っていたのはこの3つでした。

• どこを見るかを決める（この時間帯、この製品の連動、この指標）
• 数字の意味を判断する（平均で見るか最大で見るか。今回は平均を見て一度読み違えました）
• 打ち手の副作用を読む（上限を上げると何が増えるか）

読む量・並べ替え・突き合わせ・図にする作業は、すべてAIに任せました。この分担にすると、これまで「調査に何日」だった部分が数時間に縮んで、判断だけが残ります。今回時間がかかったのは、ログを揃える段取りのほうでした。

まとめ

1. ログ調査の壁は、難しさではなく量。人は全部読めないので「当たりをつけて抽出」から始めるしかなかった
2. 製品をまたぐ突き合わせは人手では何日もかかる。だから全体傾向の把握は実質不可能だった
3. 取得場所を先に押さえる。DataSpiderはログフォルダ丸ごと、Dr.Sumは期間指定ZIP、MotionBoardはシステム設定、CPUはOS側
4. 結合キーはアクセスID（Dr.Sumの要求識別子）。ここで3製品が1本の時間軸に載る
5. 作る図は4枚。分単位の推移＋上限／占有時間の帯／混雑計／症状の切り分け
6. Dr.Sumの上限はサーバー設定。ただしSQLは絞れないので、上げるとCPUは悪化する
7. 全体像と詳細が地続きになる。絵から1件のエラーまで降りられるので、原因特定まで一気につながる
8. 人に残るのは判断。どこを見るか、数字をどう読むか、打ち手の副作用をどう読むか
9. 残るボトルネックは分析ではなく段取り。今回も時間がかかったのはログを集めるところで、分析は数時間だった

いま手元にあるログは、たいてい「取ってあるけれど読まれていないもの」です。読まれていないのは怠けているからではなく、量が人の手に合っていなかっただけでした。その前提が変わりました。

データも人もAIも、つながるから、先がある。

みなさんの環境では、朝いちばんに何本の処理が同時に走っているか、把握できていますか。

このときのログの集め方、詰まった箇所、AIに出した指示そのものは、Xの記事に実録として書いています 👉 Dr.Sum・DataSpider・MotionBoardのログを1本の時間軸に載せたら、数時間で原因が出た話

（掲載した図はすべてイメージです。お客様名・関係者名・製品バージョン・日付・実測値は伏せ、一般化して記述しています）

石井 亮介（りょうさん）

データパレード 代表取締役

XContact

㈱データパレードの代表取締役で、高田馬場の町中華「一番飯店」のChief Data Officerも務めています。BIツールのセールスエンジニア・システムエンジニア・カスタマーサクセス歴15年。大学のデータサイエンス教育で講師も担当してきました。現在は自社業務のほとんどをAIに移管し、AI10部署と50を超える自動処理が24時間動く「AI経営」を実践中。その実践知をこのブログで発信しています。