可観測性の基本的なシグナルの「Traces」

相原魁氏:ようやく最後のシグナルの話です。これは「Traces」で、依存関係を持つメタデータの有向非巡回グラフです。たぶんわかりづらいと思うのですが、有効非巡回グラフは依存関係をモデリングするのに適したデータ構造で、つまり、メタデータに依存関係が持てることだけ理解してもらえれば大丈夫だと思います。

これもOpenTelemetryという指標で標準化が進んでいて、特徴は計測も保存も比較的コストが高いことです。Logsほどではないのですが、Metricsに比べるとコストが高いので、“サンプリング”といって、全部を収集するのではなく、全体の1パーセントだけを収集することで、コストとのバランスを取ることがあります。

(スライドを示して)余談ですが、OpenTelemetryはもともとOpenTracingというTracesの標準化をしていたプロジェクトと、OpenCensusと呼ばれるライブラリが合体してできたプロジェクトです。

もともとGoogleが社内で作っていたCensusというライブラリをオープンソース化したのがOpenCensusです。古くをたどると、トレーシングと呼ばれる分野も12年前くらいにGoogleがやり始めたことで、そのあたりが合わさって生まれたプロジェクトがOpenTelemetryです。

Tracesは先ほど話を聞いてもイメージがつきづらかったと思います。(スライドを示して)これは実際にコミュニティが、JaegerというTracesのライブラリを公開している画像ですが、実際Tracesはこんな感じです。

図の見方を説明すると、一番上の一番長いバーが全体の処理の時間を表していて、全体の処理のうち、各処理がどのくらいの実行時間の比率を占めているかが表現されています。

全体はたぶん732ミリセカンドで、そのうち300ミリセカンドが/customerという処理で、その次にDriver:findNearestがグラフにあるぐらいの時間かかっていてみたいな感じで、処理の依存関係ごとに実行時間を可視化してくれるのがTracesの仕事です。

これは1つのアプリケーション内で可視化するだけではありません。Microservicesは、サービスアプリケーションAからアプリケーションB、アプリケーションBが呼んでいるアプリケーションCを一気通貫でグラフに表現できるのがTracesです。このあたりのメリットは後で説明するので、いったん今回はここまでにします。

TracesとSpan

Tracesは先ほど書いてあったSpanというデータ構造をもとにしています。一つひとつのバーが処理ごとの実行時間で、これをSpanと呼び、Spanの集合体をTracesと呼びます。

今話したSpanは、処理の開始と終了のタイムスタンプと処理に関する情報を持ったデータ構造です。Spanの特徴は、0つ以上の親となるSpanを持てるので、ツリー構造に表現されます。

Propagation

Propagationというちょっと聞きなれないものがあって。これは先ほど、アプリケーションをまたいで情報を引き回すことができると説明しましたが、そのための仕様というか、概念です。

W3C Trace Contextという仕様で、「どのようにして情報をアプリケーション間で引き回すか」が標準化されていて、W3C Trace Contextでは、HTTPヘッダを使うことで情報を引き継ぐことができます。

「transparent Header」で情報が引き回されて、trace-idという一番大きな概念のトレースのIDをそれぞれで引き回すことによって、「自分はどのトレースに含まれるSpanなのか」をそれぞれが認識できるようになっています。

0つ以上の親となるSpanを持てるので、親のSpanのIDを持ちそれぞれのアプリケーションがSpanを出力することによって、最終的にトレースというまとまった単位で可視化できるようになっています。これによって、Microservicesの依存関係を可視化できるようになるといった具合です。

(スライドを示して)先ほど、実行時間の計測をログでがんばるような例が出ましたが、これはどうするべきだったかというと、本当はMetricsでやったほうがいいという話を先ほどしました。

maybeSlowが、このアプリケーション内に閉じたものだけであれば、Metricsにするだけで可観測性は十分に満たされたと言えます。しかし、仮にmaybeSlowがサービスB、サービスCにリクエストしていた場合に、単にMetricsとして表現しただけだと、遅かった原因がサービスBによるものなのか、サービスCによるものなのかがわからないわけです。

つまり、そういう複雑な依存関係を持つ場合は、トレースを収集することによって、「グラフ上でこのバーがなくなったら、サービスCではなくサービスBがボトルネックだったんだ」とわかるようになるので、単に実行時間をMetricsで表現するだけではなく、Tracesも組み合わせることによってさらなる可観測性を得られます。

先ほどOpenMetricsの話をしましたが、OpenMetricsは仕様として、外部のデータに対する参照を持てるExemplarsを持っていて、これを使うことによってMetricsとTracesを関連付けて表現できます。

(スライドを示して)先ほど話したMetricsは、実際にはグラフにプロットして人間が見るようになります。それぞれのデータポイントが、トレースのIDと紐づいていまして、ボタンをクリックすることによって、先ほどのようなトレースの画面に飛んで、Metricsが起きた瞬間にどういうことが起きていたのかという依存関係を確認できます。

ここまでのまとめ

(スライドを示して)ここまでのまとめをすると、実装に詳しくない人が状況を判断できるようにするためには、可観測性が重要です。可観測性には、3つの性質の違うシグナルがあって、自由度が高くてフォーマットを持たないLogs、詳細な情報を安価に表現できるMetrics、依存関係を表現できるTracesです。

今の話からもわかるように、それぞれが補完し合う関係にあるので、組み合わせて使うことが想定されています。Metricsはコストが安い一方で、カーディナリティが高くなるような複雑で詳細な情報は持つことができず、当然依存関係を持つこともできないので、それらを補完するためにLogsもTracesも両方あわせて収集しておく必要があります。

周辺のエコシステム

その周辺のエコシステムはAWSやGCPのような主要なクラウドプロバイダーには、それぞれのフルマネージドサービスが用意されています。例えば、AWSでログを収集するならCloudWatch Logs、GCPだったらCloud Loggingみたいな感じで、だいたい主要なクラウドプロバイダーには機能が揃っています。お金を払えば「Datadog」や「NewRelic」のようなSaaS、Software as a Serviceを使うことによって、これらを全部まとめて収集してくれるサービスもできます。

当然オープンソースもたくさんあって、「Grafana Loki」というソフトウェアや「Elasticsearch」は検索エンジンとして聞いたことがある人もいるかもしれません。だいたいこのあたりがObservability系のエコシステムです。

OpenMetricsやOpenTelemetryの話をしたのですが、このあたりを含め、可観測性周りのエコシステムは、だいたいCNCF(Cloud Native Computing Foundation)というファウンデーション周りのものが多いです。

(スライドを示して)CNCFやCloud Nativeは最近聞いたことがある人もいるかもしれませんが、初めて出てきた言葉なので軽く説明しておくと、CNCFはベンダー中立、つまり「クラウドプロバイダーに偏らないエコシステムを育成や維持して、この界隈を全部盛り上げていきましょう」というファウンデーションです。

CNCFは例えばKubernetesも所属していますが、Kubernetesに対するセキュリティのアセスメントや、そのコミュニティに属するソフトウェアが安全に進化していけるようなことをサポートしてくれるファウンデーションです。

(スライドを示して)この下にあるすごいマップが、大量のCNCF周りのソフトウェアをマップ化してくれたコミュニティが出している図です。見てわかるように、おびただしい量のソフトウェアがCNCF周りにあって、それだけ盛り上がっている界隈ということです。

先ほど話した可観測性、Metricsに関するソフトウェアやログに関するソフトウェア、トレースに関するソフトウェアでもこれだけの量があります。先ほど話したPrometheusは左上に書いてあったり、Jaegerも属していて、OpenTelemetryやOpenMetricsもあります。今まで話した話は、だいたいこのCNCFの世界で起きていることです。

現場の問題に対してLogsとMetricsとTracesをどう扱うか

LogsとMetricsとTracesという概念があるのはわかったけれど、どう使うのかが疑問だと思うので、ケーススタディというか、現場の問題を解決するにあたってこれらをどう使うのかを軽く説明をしようと思います。

(スライドを示して)まず、Metricsを収集するとアラートと呼ばれる監視を設定します。人間が四六時中Metricsに異常があるかどうかを確認するのは現実的ではないので、面倒くさい作業はコンピューターにやらせるのが一般的です。

だいたいSlackに「なんかこのMetricsはヤバい傾向だよ」みたいなことが送られてくるようになるのですが、(今回は)レスポンスの速度が遅くなっている通知を受け取ったと想定しましょう。

まずやるべきことは、Metricsを見て、どのアプリケーションのどんなリクエストが遅延したかを確認することです。Metricsでは、だいたいアプリケーションのレスポンスタイムや先ほどのエラー数みたいなものを収集しているので、それらを見ながら、どのアプリケーションのどんなエンドポイント、URIで遅延が起きていたかを確認します。

そこでまず「/bar」みたいなURIを特定した後に、今度はそれをログで確認するということで、そのログの詳細な情報を取得します。これは後で話しますが、Logs、それぞれのログには、そのログを記述するに至ったイベントを一意に識別するrequestidと呼ばれる識別子が付いていて、ログを見ることによってrequestidを取得できます。

そのrequestidは、それぞれのHTTPリクエストごとに1つだけ付与されるもので、例えばアプリケーションのアクセスログとエラーログをひもづけることもできます。なので、どんなエンドポイントが遅いのかをMetricsで特定した後に、Logsでそのエンドポイントのログを確認して、エラーログが出力されていないかどうかを確認できます。

次にやることは、エラーログが出力されていないかどうかを確認することです。その結果、エラーログがなかったとなると情報がなくて打つ手がないという感じですが、Tracesを扱うとさらに詳細な情報を取得できます。

先ほど話したように、Tracesは依存関係を表現できるので、/barというエンドポイントが実際どういうデータ、外部サービスに依存していて、どんな処理にどのくらいの時間がかかっているのかの情報を取得できるので、次にTracesから新たな情報を取得することを狙います。

Tracesもrequestidから引っ張ってこられるので、Logsに書いてあったrequestidもTracesのプラットフォームで調べることによって、MySQLにクエリして、その速度が遅延していたことまで突き止められるようになります。

最後にMySQLに何が起きていたのかを突き止めなければいけないわけですが、そこではMetricsを使えて、先ほど話したMySQL Server Exporterを導入すると、MySQLのコネクション数やレイテンシやCPUの使用率が自動的に収集されるようになっています。

そうすれば、Metricsを確認することによって、「MySQLの接続数がその時間帯に増大していた」ということまで突き止められるようになります。要は、Metricsだけでもログだけでも原因にはたどり着けなくて、それらを複合的に使うことによって問題の根本原因にたどり着くということが現場で行われていることです。

(次回につづく)