これは ZOZO Advent Calendar 2022 カレンダー Vol.2 の 17 日目の記事です。昨日の投稿は @YasuhiroKimesawa さんの「リファクタリングにおける「マクベス症候群」を予防する」でした。
今回はお仕事での話になりますが、私たちのチームではScalaで実装されたアプリケーションサーバーにて各処理や外部API呼び出しなどの実行時間・パフォーマンスを計測するために、Kamonというライブラリを使いDatadog APMでそれらを可視化し運用しています。このKamonとDatadog APMの連携で困ったことがあったのでメモ代わりに残しておこうと思います。
KamonによるAPM導入という部分についての概要はこちらの記事で詳しく述べられていますので参考にしてください。
簡潔に言うと私たちは以下の背景でKamonおよびDatadog APMの組み合わせを利用しています。
- ScalaおよびAkkaツール群を用いたアプリケーションを開発している
- Kamonはこれらをサポートしており、私たちはもともとメトリクスの取得という文脈で利用していた
- また、メトリクスの取得だけではなくトレースの取得もできるため利用を始めた
- 監視ツールとしてはDatadogを利用しているため、ここに連携させている
また、本文中で「トレース」「スパン」という用語を使いますが以下の意味で読んでいただけるとありがたいです。
| 用語 | 説明 |
|---|---|
| トレース | トレースは、アプリケーションがリクエストを処理するのにかかった時間とこのリクエストのステータスを追跡するために使用されます。各トレースは、1 つ以上のスパンで構成されます。 |
| スパン | スパンは、特定の期間における分散システムの論理的な作業単位を表します。複数のスパンでトレースが構成されます。 |
（https://docs.datadoghq.com/ja/tracing/visualization/ から引用）
ということで、ここから先はAPMを運用していて困ったことについて書いていきます。
困ったこと
Datadog APMのUIでとある処理を見ていたところエラーになっているスパンがありました。スパンを選択するとエラーの詳細が見れるメニューがあるのですが、それを開くと error: true という情報のみが表示されました。
私たちはこれを見て「何かしらのエラーが発生した」というのは分かりますが、さらに「どのようなエラーが発生した」のかが知りたいのですよね。Datadogのドキュメントを見たところ、まさに知りたかった情報が表示例として載っていました。（画像は https://docs.datadoghq.com/ja/tracing/visualization/trace/?tab=spantags#%E8%A9%B3%E7%B4%B0 から引用）
スパンのメタ情報として以下のデータを含めてDatadog APMに送信すると、このようにエラーのタイプやメッセージ、スタックトレースがUIで表示されます。（表は https://docs.datadoghq.com/ja/tracing/visualization/trace/?tab=spantags#%E8%A9%B3%E7%B4%B0 から引用して作成）
| 属性 | 説明 |
|---|---|
| error.msg | 専用のエラーメッセージを表示します。 |
| error.type | 専用のエラータイプを表示します。利用可能なタイプには、たとえば、Python の ValueError または Exception や、Java の ClassNotFoundException またはNullPointerException があります。 |
| error.stack | Datadog の UI（赤いボックスなど）で例外のスタックトレースをより適切に表示できます。 |
それでは、なぜ私たちのアプリケーションのスパンではエラー情報がざっくりしているのでしょうか。
エラーのメタ情報について
DatadogのAPMクライアント（dd-trace-java）を利用すると上記のメタ情報は自動的に付与されます。まず、このメタ情報が付与される仕組みを見てみましょう。メタ情報はスパンに対するタグとして付与されます。
具体例の方が分かりやすいと思うので、AWS SDK Javaの呼び出し処理におけるエラーの取り扱いについて注目していきます。少し横道に逸れますが、AWS SDK Javaでは「実行インターセプター」という仕組みが用意されていて、処理の開始・終了などの特定のタイミングで呼び出される任意のコードを書くことができます。
詳細については以下のAPIドキュメントを参照してください。
dd-trace-javaやKamonではAWS SDKのinstrumentationが実装されています。これによってアプリケーション開発者が追加でコードを書かなくてもAWS SDKの処理についてのトレースデータを自動的に取得できるようになっています。これらのinstrumentationでは実行インタセプターが実装されており、処理が失敗した場合（例外がスローされた場合含む）にスパンに対して何かを行うコードが記述されています。dd-trace-javaでは以下のコードになります。
onExecutionFailure() メソッドで DECORATE.onError(span, context.exception()); という部分があります。ぱっと見でここでスパンに対してエラーの情報を付与しているのではと考えることができます。ここに潜っていきましょう。DECORATE はimport文を見ると datadog.trace.instrumentation.aws.v2.AwsSdkClientDecorator.DECORATE であることが分かります。実態としては AwsSdkClientDecorator のインスタンスです。次に onError() について見ていきますが、ここには実装は定義されておらず継承ツリーを辿っていくと BaseDecorator に実装があることが分かります。
onError() ではthrowableがnullでなければ span.addThrowable(throwable instanceof ExecutionException ? throwable.getCause() : throwable); を呼び出しています。次にこちらを見ていきましょう。
addThrowable() では setTag(DDTags.ERROR_MSG, message); などタグをセットする処理が呼ばれています。ここでセットしているのが前に紹介した error.msg error.type error.stack の3種類のタグとなります。これらがメタ情報として付与されて、Datadogに送信される形になります。
では、dd-trace-javaではなくKamonを利用するとメタ情報はどうなるのでしょうか。こちらもAWS SDKの実行インタセプターを継承した AwsSdkClientExecutionInterceptor が存在しています。onExecutionFailure() メソッドで kamonSpan.fail(context.exception()).finish() を呼び出しています。
fail() メソッドではdd-trace-javaと似たようにタグを追加する処理を呼び出しています。ここで使われているタグのキーを見るとそれぞれ error.message error.stacktrace error.type となっています。しかし、これらはDatadog指定のキーと同じように見えますが若干異なります。対応表を以下に載せておきます。
github.com
| Datadogの指定するキー | Kamonの指定するキー |
|---|---|
| error.msg | error.message |
| error.type | error.type |
| error.stack | error.stacktrace |
対応表まで作れているのであれば、Kamonの指定するキーをDatadogの指定するキーに変換すれば万事解決！という風に考えられますが、どのように実現すれば良いでしょうか。次のセクションで考えていきます。
KamonのトレースをDatadog APMに送る処理
KamonからDatadog APMにトレースを送る流れについて以下の図に表しました。
アプリケーションからCore APIを利用してトレースを作成したりinstrumentationがアプリケーションから自動的にトレースを収集したりして、reporterと呼ばれるコンポーネントに送信されます。reporterはモニタリングツール毎に実装が用意されており、私たちはDatadog reporterを利用しています。ここでトレースをDatadog用のフォーマットに変換しDatadog agentに送信します。Datadog agentは受け取ったデータをDatadog本体に送信します。コンポーネントについては以下のページも参照ください。
今回注目したいのはDatadog reporter（kamon-datadog）で、このコンポーネントでトレースのフォーマットをDatadog向けに変換しています。具体的には KamonDataDogTranslatorDefault.translate() メソッド内の meta にあたる部分です。この処理ではスパンに関するタグ全てとマークと呼ばれるもの（ここではあまり関連しないので詳細は割愛）をマージしフィルタリングした上でDatadog用スパンのメタ情報として設定しています。
先ほど取り上げた、Kamonの指定するキーからDatadogの指定するキーへの変換はこの処理中では行われていません。それゆえ、Datadog APMのUIではスパンのエラー情報が無くなっているように見えているのです。
キーの変換を試してみる
手元の環境でKamonをインストールしたアプリケーションおよびDatadog agentを起動し、デバッグ中に KamonDataDogTranslatorDefault.translate() 内の処理でDatadogの指定するキーと値をメタ情報に追加してみたところ以下のようにUIで表示されました。エラータイプやメッセージ、スタックトレースが表示されて調査が捗りますね。
これによって、kamon-datadogのソースコード内でDatadogの指定するキーと値をメタ情報に追加すれば良さそうということが分かりましたので、Pull Requestを作成しました。この記事を書いている時点では特に動きはありませんが、今後マージされるととても助かります。もっと良い考え方や実装等あればコメントいただけるとありがたいです。
おわりに
Kamon経由でトレースをDatadog APMに連携する際の困ったことについて、ドキュメントやソースコードを見ながら要因を追っていき解決する実装を行ってみました。調べてみると、AWS SDK Javaには実行インタセプターという仕組みがあって便利なんだなとか、エラー時にスパンにメタ情報を付与するのはどのライブラリでも似たようなことをやっているんだなとか発見がありました。また、Kamonやdd-trace-javaといったライブラリがオープンソースということでソースコードを読んだりPull Requestを送ったりやろうと思えばできるというのもありがたかったです。
明日は @masa517 さんによる「Jetpack ComposeのSide-Effectsまとめ」です。
