今回は、第2回目で計装したコードを基に、計測したSpanに情報を追加してみます。
以下のコードを出発点にします。
app.MapGet("/weatherforecast", (ILogger<Program> logger, HttpContext context) => { var forecast = Enumerable.Range(1, 5).Select(index => new WeatherForecast ( DateTime.Now.AddDays(index), Random.Shared.Next(-20, 55), summaries[Random.Shared.Next(summaries.Length)] )) .ToArray(); try { throw new Exception("error!!!!"); } catch (Exception e) { logger.LogError(e, "error happened"); } logger.LogInformation("Response1 length: {Length}", forecast.Length); return forecast; }) .WithName("GetWeatherForecast");
今回の操作はOpenTelemetry .NETのドキュメントではここに記述されています。
SpanとActivity
.NET には従来 System.Diagnostics.Activity
という診断のために利用できるクラスがあります。
OpenTelemetry .NETでは(他の言語のOpenTelemetry実装と異なり)この言語備え付けの Activityを内部で利用しており、Activityを操作することでOpenTelemetryの計測も操作できるようになっています。この記事ではActivityクラスを使って操作する方法を紹介します。OpenTelemetryの仕様にもとづいたAPIで操作する方法もあり、そちらはOpenTelemetry Tracing Shimとして紹介されています。
Manual Instrumentation | OpenTelemetry
かんたんにいうと、ActivityとSpanは「計測するために区切られたある作業の単位」という同じ概念を表しています。
現在のSpanを取得する
第2回で紹介したASP.NET Coreで自動計装を適用している場合、Spanに情報を追加するためにはまず現在記録しているSpanを取得する必要があります。これはActivity.Current
プロパティで取得することが可能です。なお、計測していない場合などにnullが返る可能性があります。
app.MapGet("/weatherforecast", (ILogger<Program> logger, HttpContext context) => { var activity = Activity.Current; //以下略 }
タグを追加する
OpenTelemetryのSpanにはタグとよばれるキー・値のペアを追加することができます。タグの重要性については先日のObservability Conferenceの資料にも書いています。
タグはActivity.SetTag
メソッドで追加できます。
app.MapGet("/weatherforecast", (ILogger<Program> logger, HttpContext context) => { var activity = Activity.Current; activity?.SetTag("operation.value", 1); activity?.SetTag("operation.name", "Saying hello!"); //以下略 }
イベントを追加する
Spanにイベントを追加することができます。イベントはTimestampと文字列情報およびキー値のペアを持つことができます。これはActivity.AddEvent
にActivityEventオブジェクトを渡して追加できます。ActivityEventのコンストラクタでこれらの情報を指定しますが、Timestampはデフォルトで現在時刻になるので、通常は指定しないことになります。
app.MapGet("/weatherforecast", (ILogger<Program> logger, HttpContext context) => { var activity = Activity.Current; activity?.SetTag("operation.value", 1); activity?.SetTag("operation.name", "Saying hello!"); var spanTags = new ActivityTagsCollection(new KeyValuePair<string, object?>[] { new ("mode", "normal"), new ("speed", 10), }); activity?.AddEvent(new ActivityEvent("Start", tags: spanTags)); var forecast = Enumerable.Range(1, 5).Select(index => new WeatherForecast ( DateTime.Now.AddDays(index), Random.Shared.Next(-20, 55), summaries[Random.Shared.Next(summaries.Length)] )) .ToArray(); activity?.AddEvent(new ActivityEvent("End")); logger.LogInformation("Response1 length: {Length}", forecast.Length); return forecast; }) .WithName("GetWeatherForecast");
Spanの状態を設定する
これもObservability Conferenceにて発表したことにつながりますが、処理の中で異常な状態になった(通常例外が発生した)のであれば、Spanの状態もエラーとマークすべきです。これにより分析が可能になります。Activity.SetStatus
というメソッドがあるのでこれで設定できるはずなのですが、現時点ではまだこのAPIを呼び出してもOpenTelemetry側のSpanの状態がマークされません。
try { throw new Exception("error!!!!"); } catch (Exception e) { //これは現時点ではOpenTelemetry側に作用しない activity?.SetStatus(ActivityStatusCode.Error, "error happened."); logger.LogError(e, "error happened"); }
この問題は以下のIssueで議論されています。
現時点ではotel.status_code
とotel.status_description
を使って手動でタグとして設定します。また、例外オブジェクトを記録したい場合、Activity.RecordException
を使うと例外オブジェクトを格納したイベントを追加してくれます。したがってcatch節に書くであろうコードはこうなります。
try { throw new Exception("error!!!!"); } catch (Exception e) { activity?.SetTag("otel.status_code", "ERROR"); activity?.SetTag("otel.status_description", "error happened."); activity.RecordException(e); logger.LogError(e, "error happened"); }
まとめ
以上でコードはこのようになります。
app.MapGet("/weatherforecast", (ILogger<Program> logger, HttpContext context) => { var activity = Activity.Current; activity?.SetTag("operation.value", 1); activity?.SetTag("operation.name", "Saying hello!"); var spanTags = new ActivityTagsCollection(new [] { new KeyValuePair<string, object?>("mode", "normal"), new KeyValuePair<string, object?>("speed", 10), }); activity?.AddEvent(new ActivityEvent("Start", tags: spanTags)); var forecast = Enumerable.Range(1, 5).Select(index => new WeatherForecast ( DateTime.Now.AddDays(index), Random.Shared.Next(-20, 55), summaries[Random.Shared.Next(summaries.Length)] )) .ToArray(); try { throw new Exception("error!!!!"); } catch (Exception e) { // このコードは https://github.com/open-telemetry/opentelemetry-dotnet/issues/2569 によりOpenTelemetry側に作用しない //activity?.SetStatus(ActivityStatusCode.Error, "error happened."); activity?.SetTag("otel.status_code", "ERROR"); activity?.SetTag("otel.status_description", "error happened."); activity.RecordException(e); logger.LogError(e, "error happened"); } activity?.AddEvent(new ActivityEvent("End")); logger.LogInformation("Response1 length: {Length}", forecast.Length); return forecast; }) .WithName("GetWeatherForecast");
これを実行するとバックエンドで追加した情報が見えるようになります。New RelicであればSpanの状態をエラーにすると下のように赤色になります。
また属性が追加されていることもわかります。
View Span eventsというリンクをクリックするとSpanに追加したイベントの一覧が確認できます。Spanイベントに追加したタグや例外オブジェクトも確認できます。
さて、OpenTelemetry .NETのドキュメントには子スパンの作成とSpanのLinkの機能も紹介されていますが、これは改めて紹介したいと思います。