分散トレーシングのトラブルシューティングフレームワーク

原文: Distributed Tracing Troubleshooting Framework

はじめに

APMエージェントの分散トレーシングを有効にする

1. エージェントが最低限の要件を満たしていることを確認する。
2. エージェントを設定する。
3. アプリケーションを再起動する。
4. Environmentページで設定を確認する
   1. エージェントのバージョンが正しく、最低要件を満たしていることを確認します。
   2. (Owners, Admins and Add-On manager Users のみ実施可能) 「Agent Initialization」に進み、Distributed Tracingの構成設定を検索して、有効になっていることを確認します。

BrowserのDistributed Tracingを有効にする

1. お使いのBrowser Agentが要件を満たしていることを確認する。
2. ブラウザアプリケーションの「Settings」から「Application settings」を開き、「Distributed Tracing」のトグルをオンにします。

   

3. (オプション) cross-origin resource sharing (CORS)の有効化
   1. トレースしたいリクエストがあるドメインで始まり、別のドメインのエンドポイントに行く場合、それはクロスオリジン(cross-origin)のリクエストです。Browser Distributed Tracingがそれらのトレースを生成するためには、CORS共有を有効にする必要があります。
   2. リクエストがクロスオリジンであるかどうかは次のNRQLで確かめます:
      

      SELECT count(*) FROM AjaxRequest WHERE appName like '<add your service name>' LIMIT 100 FACET pageUrl, requestUrl

      特定のリクエストがクロスオリジンであるかどうかはrequestUrlを指定して確かめます。

      SELECT count(*) FROM AjaxRequest WHERE appName like '<add your service name>' AND requestUrl = ‘< add the specific request >’ LIMIT 100 FACET pageUrl
      
      

      pageUrlとrequestUrlのドメインが異なる場合、これはクロスオリジンリクエストであるため有効にして再デプロイします。

Traceが見つからない場合

1. Spanデータをクエリします。

   SELECT count(*) FROM Span WHERE entity.guid = ‘<add your entity.guid>’ SINCE 7 days ago TIMESERIES

サービスのentity.guidを見つけるには

1. APMページの矢印部分をクリックします。

   

   entity.guidにカーソルを合わせ、「クリップボード」アイコンをクリックしてクリップボードにコピーします。

2. なぜentity.guidを使うのでしょう？entity.guidを使用すると、同名のサービスが複数ある場合や、サービス名を変更した場合、複数のアカウントを持っている場合などでも、正しいサービスを見つけることができます。
3. タイムウィンドウを確認します。
4. 分散トレーシングが有効で、サービスに過去8日間のトラフィックがあった場合、スパンデータは数分以内に報告されるはずです。
   1. スパンの標準的なデータ保持期間は8日間です。

APMエージェント - トランザクションが自動的に計測されない

1. 1. APMトランザクションページを確認し、トランザクションが報告されていることを確認します。
      1. サービスに問い合わせて確認する
         

         SELECT count(*) FROM Transaction WHERE appName = ‘<add your service name>’ SINCE 7 days ago TIMESERIES

   2. トランザクションが報告されない場合は、そのAPMエージェントのインストールトラブルシューティングフレームワークを使用してください。
      • Goアプリケーション - Goエージェントでは、コードを手動で計装する必要があります。手順については、「Goアプリケーションの計装」を参照してください。
   3. サービスが HTTP を使用していない - サービスが HTTP で通信していない場合、New Relic エージェントは分散トレースヘッダーを送信しません。これは、ウェブ以外のアプリケーションやメッセージキューなどで発生する場合があります。この問題を解決するには、分散トレーシング API を使用して、呼び出し側または呼び出されたアプリケーションをインストゥルメントします。

Browser Agent

1. AjaxRequestイベントデータが報告されていることを確認します。
   1. AJAXリクエストが報告されていることをAJAX UIページで確認します。
   2. Browserサービスに問い合わせて確認します。
      

      SELECT count(*) FROM AjaxRequest WHERE appName = <add your Browser service name> SINCE 7 days ago TIMESERIES

2. AJAXリクエストによるBrowser interactionが発生しているか確認します。
3. AJAXリクエストが発生しているにもかかわらず報告されない場合は、「Browserインストールのトラブルシューティングフレームワーク」を参照してください。
4. New Relic ヘッダーが注入されていることを確認します。
   1. 確認したいリクエストを行っているアプリケーションのページを開きます。
   2. 開発者コンソールのネットワークタブに移動し、これらのリクエストの1つを見つけます。
   3. リクエストをクリックして詳細を表示し、「Request Headers」のセクションを見て、「Request Headers」の中に、newrelic（当社独自のヘッダー）またはtracestateおよびtraceparent（W3C Trace Contextヘッダー）のいずれかのラベルが付いたエントリーがあるかどうかを確認します。

欠落した、断片化した、あるいは不正確なデータのトラブルシューティング

標準的なヘッドベースの分散トレーシングにおけるサンプリングの仕組み

New Relic に到達するまでに、スパンが通過しなければならないサンプリングのラウンドは3つあります。

ヘッドベース・アダプティブ・サンプリング

ヘッドベースのサンプリングとは、完全なトレースを収集するためにトランザクションをサンプリングするかどうかを、トレースの開始時に決定することを意味します。トレースオリジンと呼ばれるNew Relicが監視する最初のサービスは、ランダムに10個のトレースを選択してサンプリングを行います。APMエージェントは直近の1分間のスループットを使用して、1分間に10個のトランザクションを均等に分散させるようにサンプリングのレートを設定します。

How New Relic distributed tracing works

完全なトレースのためにサンプリングされたこれらのトランザクションには、sampled属性にtrueの値がセットされます。この値は下流に伝わり、他のすべてのAPMエージェントに、下流のトレースも収集しsampledとマークすべきことを通知します。

スパン制限と優先度サンプリング

各APMエージェントには、エージェントのインスタンスごとに1分間に1000スパンのスパン制限があります。これはハードリミットであり、設定することはできません。この制限は以下に基づいています。

多くの分散型システムでは、平均的なマイクロサービスは1つのリクエストにつき10～20のスパンを生成するでしょう。そのような場合、エージェントのスパンの制限により選択されたすべてのスパンに対応することができ、そのサービスはトレースの完全な詳細を持っています。

しかし、サービスが複数のアプリケーションからサンプリング用にマークされたトレースを受信する人気のダウンストリームサービスであったり、重要な計装作業が行われていたりすると、この制限に簡単に達してしまいます。このような場合には、優先度サンプリングが使用されます。Priority Samplingでは、0.0～1.0のランダムな値を「priority」属性に割り当て、TransactionやTransactionError、Spansなどの関連イベントに割り当てることで、収穫サイクル全体で均等にサンプリングを行うことができます。トランザクションが sampled  と表示されている場合は、「priority」の値も引き上げられ、サンプリングされる可能性が高くなります。データの上限に達すると、エージェントは優先度の値を使ってスパンのサンプリングを開始します。これにより、ランダムなサンプリングが行われ、スパン（またはTransaction、TransactionError）イベントがサンプリングされた場合、関連するすべてのイベントがサンプリングされる可能性が高くなります。これは、各イベントタイプが独立したサンプリングプールを持っているにもかかわらず、同じ作業単位から作成されたすべてのイベントが優先値を共有しているためです。

これらの収集制限は調整できないため、制限に達した場合、適応型サンプリングで「sampled」とマークされたトレースが、優先度サンプリングではさらにサンプリングされる可能性があります。

トレースレートの制限

上記のサンプリング方法でもトレースデータが多すぎる場合、トレースを受信した後にサンプリングすることで、受信データを制限することがあります。この判断をトレースレベルで行うことで、トレースの断片化（トレースの一部だけを受け入れること）を避けることができます。

これは、高い「priority」値のスパンで「sampled」とマークされたトレースがまだサンプリングアウトされる可能性があり、インスタンスごとに1分間に10個のトレースが報告されるとは限らないことを意味しています。

ラムダのサンプリング

ラムダ関数のモニタリングでは、他のエージェントと同じサンプリング方法を使用せず、代わりに呼び出しの10%をサンプリングしてスパンを生成します。

ブラウザのサンプリング

ブラウザはスパンをサンプリングしませんが、デフォルトのアカウント制限として1分間に10Kスパンが設定されています。

スパンの欠落

断片化したトレース

アプリケーションが完全にインスツルメンテーションされていない

1. トレースを確認します - 同じスパンが常にorphanedになっていたり、トレースが常に同じ場所で断片化されていたりする場合は、インスツルメンテーションの問題である可能性があります。
   1. アプリケーションが自動的にインスツルメンテーションされていることを確認するには、使用しているNew Relicエージェントの互換性と要件のドキュメントを読んでください。
2. エージェントのインストールと設定を確認する
3. アプリケーションが自動的にインスツルメンテーションされていない場合は、カスタムインスツルメンテーションが必要な場合があります。

スパンが完了していない、または送信が遅れている

1. トレースインデックスに取り込まれるためには、スパンは20分以内に送信されなければなりません。
2. スパンは、それが表す作業のセグメントが完了するまで送信されません。

スパンがサンプルされ除外されている

エージェントは、60秒の収集サイクルごとに、エージェントのインスタンスごとに1000個のスパンを収集することに制限されています。

APM Spansのためのクエリ例

• 観測した（seen）、送信した（sent）あるいは欠落した（dropped）スパンを確認するためのサポートメトリクスのクエリ
  

  SELECT filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/SpanEvent/TotalEventsSeen')) as 'Spans Seen', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/SpanEvent/TotalEventsSent')) as 'Spans Sent', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/SpanEvent/Errors/Dropped')) as 'Spans Dropped' FROM Metric WHERE (entity.guid = '<add entity>') TIMESERIES LIMIT MAX SINCE <time window>
  
  

• スパン数のクエリ - Environment UIページを使用して、アプリケーションのホスト上で稼働しているエージェントの数を確認します。
  

  SELECT count(*) FROM Span WHERE entity.guid = ‘<add your entity.guid>’ FACET host SINCE 7 days

• サービスマップの確認 - 人気のあるダウンストリームサービスであれば、スパンやトレースがサンプリングされることが多くなります。

ブラウザ取り込みの制限

Browserエージェントはスパンのサンプリングを行いませんが、アカウントごとに1分間に約10000スパンの制限があります。ブラウザのスパンを問い合わせます。

SELECT count(*) FROM Span WHERE browserApp.name IS NOT NULL SINCE 10 minutes AGO TIMESERIES 1 minute

アプリ間が接続されない。

関係するすべてのエージェントを最新版にアップグレードします。

仲介するミドルウェアによりトレースコンテキストが欠落している可能性があります。また、プロキシがこの問題を引き起こすことがよくあります。プロキシに送信するヘッダーおよびプロキシから受信するヘッダーを確認したり、プロキシを削除したりして確認してください。

上流のサービスがDistributed Trace Payloadを作成しているかどうかの確認

SELECT count(newrelic.timeslice.value) FROM Metric WHERE (entity.guid = '<add entity>') AND metricTimesliceName LIKE ‘Supportability/DistributedTrace/CreatePayload/%’ FACET metricTimesliceName TIMESERIES LIMIT MAX SINCE <time window>

もしくは、W3C Trace ContextをサポートするAgentについては、次のクエリを使用します。

SELECT count(newrelic.timeslice.value) FROM Metric WHERE (entity.guid = '<add entity>') AND metricTimesliceName LIKE ‘Supportability/TraceContext/Create/%’ FACET metricTimesliceName TIMESERIES LIMIT MAX SINCE <time window>

下流のサービスがDistributed Trace Payloadを受信しているかどうかの確認

SELECT count(newrelic.timeslice.value) FROM Metric WHERE (entity.guid = '<add entity>') AND metricTimesliceName LIKE ‘Supportability/DistributedTrace/AcceptPayload/%’ FACET metricTimesliceName TIMESERIES LIMIT MAX SINCE <time window>

もしくは、W3C Trace ContextをサポートするAgentについては、次のクエリを使用します。

SELECT count(newrelic.timeslice.value) FROM Metric WHERE (entity.guid = '<add entity>') AND metricTimesliceName LIKE ‘Supportability/TraceContext/Accept/%’ FACET metricTimesliceName TIMESERIES LIMIT MAX SINCE <time window>

1. 分散トレーシングが有効になっていないサービスによるスパンの欠落
2. 様々なソースからのスパンをつなぎ合わせる
   1. Zipkinは、W3C Trace Context Headersをサポートしていない例です。

奇妙に見えるデータ

1. 説明できない時間差
   1. 一般的に、クライアントの時間がサーバーの時間よりも長い場合や時間の差が大きい場合は、ネットワークの遅延、DNSの解決遅延、ロードバランサー、キューの時間など、New Relicエージェントでは計測できないものが原因となります。
2. 時刻のずれ
   1. New Relic エージェントはヘッダーに設定された時間に依存しているため、ヘッダーに誤った時間が設定されていると、トレースの時間に大きなギャップが生じることになります。
      1. NTPによるサーバーの時刻確認
      2. リクエスト・キューイングを報告するためのガイドに従っている場合、ヘッダーのタイムスタンプが正確であることを確認します。
3. トレースデータを他の報告データと比較し、正確さを確認します。
   1. 1. トランザクショントレースは、プロセス中の作業に対する分散トレースと同様のレベルの詳細を持ちますが、すべてのタイミングと計測は同じエージェント内で行われます。Distributed Traceの断片が見つからない場合は、Transaction Tracesで同様のトレースを確認してください。
         1. 1. トランザクショントレースでは常に計測されているが、分散トレースでは常に計測されていない場合、エージェントは正しく計測されているが、サンプリングによってフラグメントが取りこぼされている可能性があります。
            2. 作業のセグメントが、トランザクショントレースでは常に報告されるが、分散トレースでは報告されない場合、記録された分散トレースの最後のセクションを確認してください。トレースの断片の前に外部呼び出しが発生している場合、ヘッダーが適切に渡されていないことが考えられます。APMエージェントの場合は、サポートメトリクスを照会して、ヘッダーが作成され、受け入れられていることを確認します。下流のサービスがNew Relicでも監視されている場合は、下流のサービスで同じ照会を実行します。

         SELECT filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/AcceptPayload/Success')) as 'Traces Successfully accepted', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/AcceptPayload/Exception')) as 'Exception occurred ', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName LIKE 'Supportability/DistributedTrace/AcceptPayload/Ignored%') as 'Ignored', filter(max(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/AcceptPayload/ParseException')) as 'Parse Exception', filter(max(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/CreatePayload/Success')) as 'Create Success', filter(average(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/CreatePayload/Exception')) as 'Create Exception' FROM Metric WHERE (entity.guid = '<add entity>') TIMESERIES LIMIT MAX SINCE 7 days ago
         
         

         もしくは、W3C Trace ContextをサポートするAgentについては、次のクエリを使用します。

         SELECT filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/TraceContext/Accept/Success')) as 'Accept Success', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/TraceContext/Accept/Exception')) as 'Accept Exception', filter(count(newrelic.timeslice.value), WHERE metricTimesliceName LIKE 'Supportability/DistributedTrace/AcceptPayload/Ignored%') as 'Ignored', filter(max(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/AcceptPayload/ParseException')) as 'Parse Exception', filter(max(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/CreatePayload/Success')) as 'Create Success', filter(average(newrelic.timeslice.value), WHERE metricTimesliceName = ('Supportability/DistributedTrace/CreatePayload/Exception')) as 'Create Exception' FROM Metric WHERE (entity.guid = '<add entity>') TIMESERIES LIMIT MAX SINCE 7 days ago
         
         

よくある質問

トランザクショントレースのトレースIDと一致する分散トレースが見つからないのはなぜですか？

簡単に言うと、サンプリングです。非常に似た名前にもかかわらず、トランザクショントレースと分散トレースはかなり異なります。トランザクション トレースは、スパンではなくセグメントで表現された各作業単位を持つ、単一のトランザクション内の作業の流れに関するさらなる詳細情報を提供します。トランザクショントレースにはExternal Request（外部サービスへの通信）がありますが、測定とレポートはすべてサービス内で行われます。トランザクションイベントは、トランザクションが完了した後の継続時間に基づいて、完全なトランザクショントレースとしてサンプリングされます。

対照的に、標準的な分散トレーシングはトレースの開始点、つまり「ヘッド」でサンプリングします。分散トレースがリクエストの実行に関与するすべてのサービスを通過する前に、トレースの始点がランダムにサンプリングを決定するため、経過時間はサンプリングの決定に影響を与えず、同じ作業に対してトランザクショントレースと分散トレースが収集される可能性はまったくの独立です。あるトランザクションがサンプルトレースとトランザクショントレースの両方に含まれていたとしても、分散トレースが他の2つの方法のいずれかによってサンプルアウトされる可能性があります。

「サンプリングされた(sampled)」と表示されたトランザクションのうち、分散トレースを持つものが少ないのはなぜですか？

もう一度言いますが、サンプリングです。「sampled: true」と表示されていると、サンプリングされているような印象を受けますが、これはトレースに関与するすべてのエージェントがトレースのための情報を収集するためのシグナルとしてトレースの開始時に設定されるものであり、プライオリティサンプリングやトレースレート制限が作動した後のトレースの終了時に設定されるものではないことを覚えておくとよいでしょう。

これにはいくつかの一般的な原因があります。お客様のサービスが人気のある下流サービスである場合、そのサービスを呼び出す各エージェントは、お客様のサービスがトレースのために自身のトランザクションをサンプリングしているため、「sampled」マーカーの付いたインスタンスごとに1分間に10個のトレースを送信します。これは、1分間に1000スパンの制限を容易に超えてしまいます。エージェントは全体のトレースを好むため、断片的なトレースを大量に報告するのではなく全体のトレースを削除してしまいます。

1つのトレースで多くの作業が行われている場合、やはりサンプリングの限界に達し、トレース全体がサンプリングされなくなることがあります。1つのトレースに複数のトランザクションが含まれることがあります。