1秒の読み取り遅延から、OSのCPU stealまでたどり着いた
私は現在高校生で、個人でソフトウェアの開発・運用をしています。最近導入したNew Relicが予想以上に便利だったので、実際の障害調査で何ができたのか紹介します。
ScyllaDBを使っているシステムで、設定の読み取りに1,094msかかったという通知がDiscordに届きました。
アプリの処理が遅いのか、ScyllaDBが遅いのか、それともネットワークなのか。通知だけでは分かりません。
そこで、最近使い始めたNew Relicと、自作のNew Relic × ChatGPTプラグインを使い、当時の監視データを直接調べてみました。
結果として、遅延が発生した時間帯に以下の記録を確認できました。
- Oracle CloudのAMDインスタンスで、CPU stealが最大72.20%
- 同じ時間帯にCPU iowaitとディスクI/O利用率の指標が上昇
- ScyllaDBのReactor関連指標が特定ノードで突出
- アプリの遅延から約32秒後に、ScyllaDBのノード間RPCタイムアウトを記録
- OSログではAPTの定期処理も動いていた
ただし、CPU stealが今回の1.1秒遅延を直接引き起こしたとまでは確定していません。 この記事では、実際に確認したデータと仮説を分けて紹介します。
そもそも、なぜChatGPTにつないだのか
最近、監視にNew Relicを使い始め、AIに補助してもらいながら調査していました。
ただ、そのたびにNew Relicでデータを見て、AIに渡して、追加で必要な情報をまた取りに行くという、自分が間に挟まる作業が面倒でした。
「だったらChatGPTが直接New Relicを読めばいいのでは？」と思い、New Relicの公式MCP Serverを利用した連携ツールを作りました。
現在はGitHubで、各自が自分専用のChatGPT SitesとPluginを構築するためのOSSとして公開しています。
今回の記事は、ツールの作り方よりも、それを実際の障害調査で使うと何ができたかが中心です。高校生の自分が使い始めたばかりのNew Relicで、ここまでデータを調べられたことにも驚きました。
調査対象：Discordに届いた2件の通知
まず、アプリ側に残っていた記録です。
| 発生時刻（JST） | 処理 | 結果 | 総所要時間 | driver callback待ち |
|---|---|---|---|---|
| 2026/11/4 15:54:05 | 設定のSELECT | TimeoutError | 1,501.419ms | 1,500.423ms |
| 2026/11/4 23:20:31 | 設定のSELECT | 遅延後に成功 | 1,094.104ms | 1,092.285ms |
どちらも、読み取り開始前の待機より、driver callbackを待っている時間が圧倒的に長い状態でした。
ただしcallback待ちには、DBドライバー内部、ネットワーク、ScyllaDB側の応答などが含まれます。「ScyllaDBのサーバー処理自体に1秒かかった」という意味ではありません。
以下では、後者の11月4日23:20:31（JST）を重点的に調べます。
データの扱いについて
数値はNew Relicで実際に取得した値です。ホスト名・内部IP・IDなどは公開用に伏せ、ScyllaDBの監視対象はA/B/Cと表記します。運用上のノード対応は確認済みですが、収集メトリクスに付くhost.hostnameは収集元を表すため、ノード判定には使用していません。
調査方法：時刻を伝えて、New Relicから直接データを取得
ChatGPTで自作プラグインを選び、次のように依頼しました。
2026年11月4日23:20:31（JST）にScyllaDBの読み取りが約1.1秒遅延した
New Relicから同時刻のCPU steal、Reactor、I/O、OSログを調査して
事前の比較区間と比べ、観測事実・相関・推測を分けて報告して
裏側では、次のような流れでデータを取得します。
ChatGPT
└─ 自作New Relic × ChatGPT Plugin
└─ 所有者限定のChatGPT Site / MCP Worker
└─ New Relic公式MCP
├─ Metric（CPU・Reactor・I/O）
└─ Log（OS・ScyllaDB）
プラグインが読み取り専用のNRQLを実行し、戻ってきた集計値を使って次の調査対象を絞ります。
特に便利なのは、アプリから通知された過去時刻をそのまま調査の起点にできること。ログのコピーやメトリクスの転記を繰り返さずに、同じ会話の中で調査を進められました。
発見1：Oracle Cloud AMDでCPU stealが大きく上昇
New Relicのインフラメトリクスで、対象ホストのインスタンス種別を確認しました。
- 対象：Oracle Cloud
VM.Standard.E2.1.Micro（AMD） - 比較対象：
VM.Standard.A1.Flex（Arm）など
host.cpuStealPercentを遅延前の時間帯と比較すると、次の結果になりました。
| AMDホストのCPU steal | 事前比較区間 | 遅延を含む区間 |
|---|---|---|
| 時間帯（JST） | 22:50〜23:10（20分） | 23:19〜23:22（3分） |
| 平均 | 4.19% | 30.44% |
| 最大 | 37.21% | 72.20% |
比較区間にも瞬間的な高い値が含まれるので、完全に平常な区間だとは決めつけません。それでも、遅延時の平均値は大きく違っていました。
1分ごとの推移を見ると、さらに分かりやすくなります。
| 時刻（JST） | CPU steal平均 | CPU使用率平均 |
|---|---|---|
| 23:18 | 3.15% | 7.82% |
| 23:19 | 5.77% | 11.62% |
| 23:20 | 47.19% | 74.58% |
| 23:21 | 38.37% | 68.18% |
| 23:22 | 4.74% | 12.49% |
| 23:23 | 4.05% | 9.46% |
この時間帯、ArmホストのCPU steal平均は約0.19%でした。
CPU stealは、仮想CPUが実行したい処理を抱えていても、仮想化ホストのスケジューリングなどによって実行できなかった時間を表す指標です。
今回のAMDホストでは、実行待ちが大きく増えていたことは確認できました。一方、ハイパーバイザー側でなぜそうなったのか、CPU stealが特定の読み取りを直接遅らせたかは、この指標だけでは判断できません。
発見2：I/Oの指標も同時に変化していた
CPU steal以外のホストメトリクスもNew Relicで照合しました。
| AMDホストの指標 | 事前比較区間の平均 | 遅延を含む区間の平均 | 遅延区間の最大 |
|---|---|---|---|
CPU iowait（host.cpuIoWaitPercent） |
0.84% | 10.13% | 35.45% |
ディスクI/O利用率（host.disk.totalUtilizationPercent） |
2.23% | 31.60% | 97.67% |
どちらも遅延時に上昇していました。ディスクの容量使用率ではなく、ディスクI/Oの利用率を示す指標です。
一方、取得できたScyllaDBのscylla_database_queued_readsとscylla_io_queue_disk_queue_lengthは、同時刻の観測値ではいずれも最大0でした。
つまり、ホスト側のI/O指標に変化があっても、ScyllaDBの読み取りキューが継続的に積み上がっていたとは言えません。 収集間隔より短い詰まりは見逃している可能性もあります。
発見3：OSログにAPT処理とScyllaDBのRPC timeout
今回、New Relicにはメトリクスだけでなくlinux_syslogも収集されていました。
遅延時刻付近のログを調べると、こんな時系列になりました。
| 時刻（JST） | 確認できた記録 |
|---|---|
| 23:20:05 |
apt-daily.service開始 |
| 23:20:08 |
apt-news・esm-cache開始 |
| 23:20:31 | Botの読み取りが約1.1秒遅延したことを通知 |
| 23:21:03 | ScyllaDBのfailure detectorがRPC timeoutを記録 |
| 23:21:04 | 同様のRPC timeoutを記録 |
| 23:21:34 |
apt-daily.service終了 |
ScyllaDBのログの形式は、匿名化すると次のようなものでした。
scylla: [shard 0: gms] direct_failure_detector
unexpected exception when pinging <peer-id>:
seastar::rpc::timeout_error (rpc call timed out)
アプリ側の遅延記録とは別に、ScyllaDB内部でもノード間RPCタイムアウトが観測されていたことになります。
ただし、そのタイムアウトはアプリ側の通知から約32秒後です。同じ原因による連続した事象かどうかは未確定で、同時刻に近いというだけで因果関係を断定することはできません。
なお、apt-daily.serviceには累積CPU時間1分8.787秒の記録が残っていました。これはサービスの単純な経過時間ではありません。APTが実行されていたことと、CPU stealが増えた原因がAPTであることは別です。
発見4：Reactorの異常は特定ターゲットに偏っていた
ScyllaDBのメトリクスをノードごとに見直しました。
scylla_reactor_utilization（shard 0） |
事前比較区間の平均 | 遅延を含む3分間の平均 | 3分間の最大 |
|---|---|---|---|
| ターゲットA（AMD） | 1.137 | 5.288 | 13.516 |
| ターゲットB | 0.566 | 0.561 | 0.615 |
| ターゲットC | 0.394 | 0.381 | 0.421 |
この数値は1を大きく超えているため、そのままCPU使用率やReactorの稼働割合として解釈できません。 収集・変換・集計上の意味を確認する必要があります。ここでは、値が偏っていたという事実までにとどめます。
scylla_reactor_stalls_sumもターゲットAで高い集計値を返しましたが、Summary形式の指標に対する集計なので、その値をstallの発生回数や遅延時間として直接使うことは避けました。
ここで一つ、NRQLの落とし穴
最初はhost.hostnameを使ってノード別に比較しようとしました。しかし、ScyllaDBメトリクスでは3ターゲットすべてに収集元ホストの名前が付いていました。
そのままFACET host.hostnameを使うと、複数ノードが一つのホストにまとまってしまいます。
そこでkeyset()で存在する属性を確認し、ノードごとの比較にはFACET scrapedTargetNameを使いました。
監視データの属性が何を指すのかを確認できることも、New Relicを使って調査を進める上で重要でした。
実際に使ったNRQL
調査の再現性のために、代表的なクエリを載せておきます。日時はUTCで指定しています。自分の環境では属性名や収集されるメトリクスを先に確認してください。
① まず取得可能な属性を調べる
SELECT keyset()
FROM Metric
WHERE metricName = 'scylla_reactor_utilization'
SINCE '2026-11-04 14:19:00'
UNTIL '2026-11-04 14:22:00'
② AMDホストのCPU stealを時系列で追う
SELECT average(`host.cpuStealPercent`) AS steal,
max(`host.cpuStealPercent`) AS peak
FROM Metric
WHERE metricName = 'host.cpuStealPercent'
AND `host.hostname` = 'YOUR_HOSTNAME'
TIMESERIES 1 minute
SINCE '2026-11-04 14:18:00'
UNTIL '2026-11-04 14:24:00'
③ ScyllaDBのReactor指標をターゲット別に比較
SELECT average(scylla_reactor_utilization) AS avg,
max(scylla_reactor_utilization) AS peak
FROM Metric
WHERE metricName = 'scylla_reactor_utilization'
AND shard = '0'
FACET scrapedTargetName
SINCE '2026-11-04 14:19:00'
UNTIL '2026-11-04 14:22:00'
LIMIT 10
④ ScyllaDB内部のRPCタイムアウトを探す
SELECT count(*) AS n
FROM Log
WHERE message LIKE '%rpc call timed out%'
SINCE '2026-11-04 14:19:00'
UNTIL '2026-11-04 14:22:00'
新しい環境であれば、metricNameやログの取り込み状況も確認してください。これらのクエリを実行したからといって、必ず同じメトリクスや事象があるとは限りません。
New Relic × ChatGPTで何が効率化できた？
今回、最も変化したのはデータを取得してAIに渡すまでの作業です。
| 工程 | 以前 | 今回 |
|---|---|---|
| 調査したい時刻を指定 | 自分でNew Relicを操作 | ChatGPTに時刻を伝える |
| 追加メトリクスを取得 | 自分が取りに戻ってAIに渡す | ChatGPTがプラグイン経由で照会 |
| ノード間・時間帯の比較 | データをやり取りしながら比較 | 会話内でNRQLを繰り返し実行 |
| OSログとの照合 | ログを探して渡す | 同じ調査の流れでLogを検索 |
| 結論の確認 | 人が判断する | 引き続き人が確認する |
特にNew Relic側で役立ったと感じたのは、次の3点です。
過去のデータが残っていること。 Discordの通知を見てから、数時間前のCPU stealやReactor指標を時刻指定で調べ直せました。
メトリクスとログを一つの基盤から照合できること。 CPU、ディスクI/O、ScyllaDB、systemd、RPC timeoutまで調査対象を広げられました。
公式MCPからプログラムで監視データにアクセスできること。 ChatGPTに必要なNRQLを使わせ、観測結果を受け取って次の照会に進めました。手作業の情報受け渡しを減らしたい、という当初の目的に合っています。
今回は手動調査とプラグイン調査の所要時間を同条件で測定していません。 したがって「調査時間を何％削減できた」といった数値は出せません。効率化できたと確認できるのは、主に人が手動で情報を転記する工程を省けたことです。
なお、New Relicの公式MCPツールリファレンスでは、MCPツールの利用量や計測単位について説明されています。運用時には権限・利用量・料金も確認する必要があります。
では、原因はCPU stealだったのか？
今回の証拠を整理すると、こうなります。
| 分類 | 分かったこと |
|---|---|
| 観測できた | AMDホストでCPU stealが最大72.20%、23:20の1分平均47.19%に上昇 |
| 観測できた | 同じ時間帯にCPU iowait・ディスクI/O利用率の指標も上昇 |
| 観測できた | アプリの読み取りに1,094msかかり、大部分がdriver callback待ち |
| 観測できた | 約32秒後にScyllaDB内部のRPC timeoutを記録 |
| 観測できた | Reactor関連指標がターゲットAで他のターゲットより高い |
| 有力な仮説 | CPU実行待ちを含むAMDホストのリソース状況がDB応答へ影響した可能性 |
| まだ言えない | CPU steal・APT・I/Oのどれが直接の原因か、個別の読み取りとRPC timeoutが同一原因か |
少なくとも「DBの読み取りが1秒かかった」という通知を出発点に、どの時間帯の、どのホストで、どの種類の異常が起きていたのかまで調べることができました。
原因の最終確定には、より細かい時間粒度のデータや、読み取り遅延の分布、ネットワーク・ドライバー側の情報を重ねる必要があります。今回のデータから正しいp95・p99を算出できていないため、それらの値は掲載していません。
高校生の自分がNew Relicをおすすめしたくなった理由
ここまで書いてきたとおり、今回はアプリの通知1件を起点に、CPU steal、ディスクI/O、ScyllaDBのReactor指標、OSログ、RPCタイムアウトまで確認できました。
私はNew Relicを使い始めたばかりの高校生ですが、正直ここまで調べられるのはすごいと感じました。今回、特に良かったのは次の点です。
- データがまとまっている：メトリクスだけでなくOSログも確認でき、同じ時刻の出来事を追いやすい
- 過去に戻って調べられる：Discordの通知を見てからでも、発生時刻を指定して当時の指標を比較できた
- NRQLで深掘りできる：ホスト、監視ターゲット、時間帯などを切り替えて集計できた
- 公式MCPでChatGPTから調べられる：自作Pluginを通じてデータの取得と比較を任せ、自分が毎回データを転記する手間を減らせた
特に嬉しかったのは、「どこが遅いか分からない」で止まらず、次に確認すべき指標を自分で探し続けなくて済んだことです。もちろん、ChatGPTが判断を間違えることもあるので、最後の確認は必要です。
個人的には、学生のうちからこうした監視ツールに触れておくのをおすすめしたいです。卒業後も、たぶんNew Relicを使い続けていると思います。
学生じゃなくても無料で始められる
さらに嬉しいのが、New Relicには学生限定ではない、期限付きトライアルとは異なる無料枠があることです。公式の無料プランでは、次の内容が案内されています（2026年11月時点）。
| 一般向けFreeプラン | 含まれるもの |
|---|---|
| データ取り込み | 月間100GB |
| フルプラットフォームユーザー | 1名 |
| ベーシックユーザー | 無制限 |
| 対応領域 | APM、インフラ監視、ログ管理などの機能 |
| クレジットカード | 登録不要 |
自分でサーバーやアプリを運用しているなら、まずは無料でメトリクスやログを集めてみるだけでも、調査の幅が広がると思います。100GBを超える利用や追加の有料機能などには条件があるので、利用前に料金ページを確認してください。
GitHub Student Developer Pack対象者なら学生向け特典も
GitHub Student Developer Packを使える学生は、New Relic for Studentsも確認する価値があります。対象者向けに、公式ドキュメントでは次の特典が案内されています。
| New Relic for Students | 内容 |
|---|---|
| 利用期間 | 2年間 |
| データ取り込み | 月間500GB |
| フルプラットフォームユーザー | 3名 |
| Syntheticsチェック | 月間10,000回 |
ただし、2026年11月時点ではStudent Editionのセルフサービス申請は一時停止されており、公式ドキュメントでは資格要件を確認したうえでサポートケースから申し込むよう案内されています。学校・学習状況などによる資格条件もあるため、詳細はNew Relic for Studentsの公式案内をご覧ください。なお、この記事は学生特典の適用実績を紹介するものではありません。
興味があれば、まずは無料アカウントから
New Relicが初めての人も、最初は簡単なサーバー監視やログ収集から始めると分かりやすいと思います。今回のように障害が起きてから慌てるだけでなく、後から振り返れるデータを普段から残しておけるのが大きな魅力です。
👉 New Relicの無料アカウントを作成する（公式・日本語）
これはNew Relicの公式登録ページへのリンクです。記事で使ったChatGPT Sitesや自作Pluginを利用するには、New Relic側のMCP利用権限やChatGPT側の対応プランなど、別途条件があります。New Relicに無料登録するだけで本記事の連携環境まで無料で使えるという意味ではありません。
まとめ：AIに答えを出させるより、調査を進めさせる
今回、New Relicを最近使い始めた自分が、毎回AIに監視データを渡す作業を減らしたくて作ったプラグインを、実際のScyllaDB調査に使ってみました。
印象的だったのは、New RelicのメトリクスとOSログを同じ時刻で追うことで、アプリ側の通知だけでは見えなかったCPU stealの急増やScyllaDB内部のRPC timeoutまで確認できたことです。
そして公式MCPのおかげで、必要なデータの取得をChatGPTから直接進められました。
一方で、値が1を超えるReactor指標や、収集元を表すhost.hostnameなど、AIが取得した値をそのまま信じてはいけない場面もありました。重要なのは、観測できたことを積み上げ、分からないことを分からないまま残すことだと思います。
New Relicでデータを集め、ChatGPTで調査のやり取りを省力化し、最後は自分で解釈を確認する。この組み合わせは、今後の障害調査でも使っていきたいです。
高校生の自分でも実運用の障害調査にここまで活用できたことが、New Relicをおすすめしたい一番の理由です。学生にも、学生ではない個人開発者にも、まず無料枠から触れてみてほしいと思います。
- New Relic × ChatGPT（GitHub / MITライセンス）
- セットアップ用Release v0.3.0
- New Relic公式MCPの概要
- New Relic MCPツールリファレンス
- New Relicの無料アカウント登録（公式）
- New Relic for Students（公式）
※本記事は個人の運用環境における実測・検証記録です。「New Relic × ChatGPT」は非公式の個人開発OSSであり、New RelicおよびOpenAIの公式提供物ではありません。各自の所有者限定Siteを構築する方式で、別ユーザー環境・複数ユーザー間の完全な認証分離などは未検証です。