Article by: Sergiy Dybskiy
スタックトレースは便利ですが、教えてくれるのは「何が壊れたか」だけで、「なぜ壊れたのか」を教えてくれることはほとんどありません。例外が発生すると、物事が崩れた瞬間のスナップショットは得られますが、そこに至るまでのコンテキストは消えてしまいます。
そこで Logs の出番です。適切な場所に Logs があることで、何時間も悩む羽目になるか、5 分で直せるかの分かれ道になります。最近私が遭遇した実際のバグを例に、その意味をご説明します。
ボットから AI 搭載の Next.js エンドポイントを守る
私は WebVitals という、AI を活用した Next.js アプリケーションを開発していました。ドメインを入力すると、パフォーマンスデータを取得するために一連のツール呼び出しを実行し、その結果を AI エージェントが解析して、Web Vitals を改善するための実行可能な提案を返します。
フロントエンドでは会話のやり取りを扱うために、AI SDK の useChat フックを使っています。

/api/chat エンドポイントは標準的な Next.js の API ルートなので、誰でもどこからでもアクセスでき、各リクエストにはコストがかかります(OpenAI は無料ではありません)。そのため、ボットや悪意ある攻撃者がリクエストを大量に投げて請求額を跳ね上げようとするのを防ぐ仕組みが必要でした。
Vercel にはそのための良い解決策があります。
checkBotId 関数によるボット対策です。受信したリクエストを見て、ボットからのものかどうかを判定します。シンプルで効果的で、ユーザーに横断歩道を選ばせる CAPTCHA も不要です。

Firefox と Safari にだけ影響する本番バグ
ローカル開発ではすべて完璧に動いていました。本番にデプロイして、Chrome でテストしても問題なし。ところが、Firefox を開いた瞬間に状況が変わりました。

「Access denied.」Chrome では通っていた同じリクエストが、Firefox ではブロックされていました。Safari でも同じ問題が起きていました。
Sentry を確認すると、エラー自体は複数のブラウザで発生しているように見えましたが、影響を受けているのは Firefox と Safari だけでした。Chrome のユーザーは問題ありませんでした。

修正を試み、何度もリリースし、何度も試しましたが、それでもエラーは繰り返し戻ってきました。スタックトレースも役に立ちません。分かるのはこれらのブラウザに対してボット判定が true になっている、ということだけです。なぜ Chrome ではなく Firefox と Safari がボットとして判定されるのか…
スタックトレースではその答えは分かりませんでした。
欠けているコンテキストを捉えるために Logs を追加
これはエラーだけでは足りないコンテキストが必要になるタイプの問題です。checkBotId 関数が判定を下すとき、どんなデータを見ていたのかを確認する必要がありました。
そこで Logs を 1 行追加しました。

難しいことはしていません。関数に渡されたユーザーエージェント文字列と一緒に、ボット判定の結果をログするだけです。ボット対策は通常ユーザーエージェントを調べて動くので、これが記録すべきデータだと考えました。
ここで重要なのは、Sentry の Logs はハイカーディナリティだという点です。任意の属性を好きなだけ渡せて、あとからそれらで検索・フィルタできます。どの属性が「重要」かを事前に決める必要はありません。役に立ちそうなものをログに残しておけば、あとは Sentry が面倒を見てくれます。
Sentry Logs を使って根本原因を特定する
Logs を入れたので、Sentry の Logs ビューへ移動し、「Bot ID check result」のメッセージを検索しました。結果を素早く見渡せるように、isBot 属性を列として追加しました。(Sentry では、boolean は false が 0、true が 1 と表示されます。)

ボット判定を通過したリクエスト(isBot: 0)を見つけました。詳細を見ると、ユーザーエージェントは想定どおりで、ごく標準的な Chrome のユーザーエージェント文字列でした。

次に、失敗したリクエスト(isBot: 1)を確認しました。ユーザーエージェントは想定していたものではありませんでした。

ブラウザのユーザーエージェントではなく、ai-sdk が見えていました。AI SDK がブラウザのものではなく自分自身のユーザーエージェント文字列を送っていたのです。
これですべての説明がつきました。AI SDK がバックエンドへリクエストを送るとき、独自のユーザーエージェントを使います。Vercel のボット対策は ai-sdk を見て、「本物のブラウザではない」と(もっともな判断として)判定します。ボット検知。アクセス拒否。
では、なぜ Firefox と Safari だけだったのでしょうか。
それは、それらのブラウザ(あるいはそれらのブラウザでの私の設定)の何かが原因で、ブラウザのユーザーエージェントではなく AI SDK のユーザーエージェントが使われる状態になっていたからです。Chrome だけは、たまたま正しいユーザーエージェントがそのまま送られていました。
この推測を確かめるために、私は Sentry のトレース接続機能を使いました。Sentry では、すべてがトレースで関連付けられているため、Logs のエントリから完全なトレースビューへ戻って、リクエストのより広いコンテキストを確認できました。

案の定、トレースで、Firefox から来ていることが確認できました。これで謎は解けました。
データが物語ったあとに問題を修正する
解決策はシンプルでした。Vercel のファイアウォール設定で、ユーザーエージェントに ai-sdk を含むリクエストはボット対策をバイパスするルールを追加しました。

ルールを保存し、変更を公開して、Firefox でもう一度試しました。
動きました。Access denied エラーはもう出ません。気になる方のために、この件は AI SDK の GitHub issue でも追跡されています。
このバグが示した Logs とデバッグの価値
このバグは Logs がなければ原因特定にもっと時間がかかっていたはずです。エラーそのもの(「Access denied」)からは、なぜ拒否されているのかが何も分かりませんでした。スタックトレースで分かったのは、どこで起きたかだけで、何が原因になったデータだったのかは分かりませんでした。
ポイントは次のとおりです。
Logs はスタックトレースでは得られないコンテキストを提供する
デバッグでは、ある時点でデータがどういう状態だったのかを知る必要があることがよくあります。エラーは失敗した瞬間を捉えますが、Logs はそこに至るまでの道筋を捉えます。ハイカーディナリティな属性は強力
isBot や userAgent のように、任意の属性でログを検索できると、データの切り分けが非常に簡単になります。どの属性が役に立つかを事前に予測する必要はありません。トレース接続がすべてを結び付ける
Logs 単体でも有用ですが、Logs から完全なトレースへ(またはその逆へ)飛べると、全体像が手に入ります。今回の場合は AI SDK のユーザーエージェントが Firefox のリクエストから来ていることを確認できました。
すでに Sentry をエラートラッキングに使っているなら、次は Logs を追加するのがおすすめです。新規プロジェクトなら Sentry.logger API を直接使うことができます。Pino のような既存のロギングがある場合は、ログ連携を使ってそれらのログを Sentry に自動で流し込むことが可能です。
アプリケーションから構造化ログを Sentry に送り、デバッグとオブザーバビリティに役立てる方法については、Next.js Logs のドキュメントを参照してください。あるいは、Logs クイックスタートガイドを参照して、すぐに使い始められます。
問題が起きても、常にエラーとして表に出るわけではありません。ときには、何が起きていたのかを確認するだけで十分です。
Original Page: Not everything that breaks is an error: a Logs and Next.js story
IchizokuはSentryと提携し、日本でSentry製品の導入支援、テクニカルサポート、ベストプラクティスの共有を行なっています。Ichizokuが提供するSentryの日本語サイトについてはこちらをご覧ください。またご導入についての相談はこちらのフォームからお気軽にお問い合わせください。


