銀の光と碧い空

クラウドなインフラとC#なアプリ開発の狭間にいるエンジニアの日々

OpenTelemetry .NETを理解する (5) HttpClientによる外部通信処理を計測する

前回はスパンに情報を追加しました。

tech.tanaka733.net

次にトレースをさらにスパンで区切ってどの処理に時間がかかっているか計測することにします。スパンは作業の単位で区切ります。原理的には1メソッド1スパンで記録することもできますが、計測のオーバーヘッドや分析のノイズになることから、意味のある作業の単位でスパンを作成するのがおすすめです。そして、トレースで注目したいボトルネックになりうる作業の単位としては、HTTPでの外部呼び出しやデータベースへの呼び出しが典型的です。そのため、OpenTelemetry .NETでもそれらのライブラリに対して自動計装する機能が用意されています。今回は、HttpClientによる外部呼び出しを自動計装する機能を紹介します。

最初のコードはこのような状態です。

app.MapGet("/external", async () =>
{
    var client = new HttpClient();
    var req = await client.GetAsync("http://httpbin.org/get");
    var res = await req.Content.ReadAsStringAsync();
    Console.WriteLine(res);
    return res;
});

app.MapGet("/external/error", async () =>
{
    var client = new HttpClient();
    var req = await client.GetAsync("http://httpbin.org/status/502");
    try
    {
        var res = await req.EnsureSuccessStatusCode().Content.ReadAsStringAsync();
        Console.WriteLine(res);
    }
    catch (Exception e)
    {
        Console.WriteLine(e.Message);
    }
});

HttpClientの自動計装については、次のようにASP.NET Coreの最初の設定時にAddHttpClientInstrumentationメソッドを呼び出すことで行います。そのため、個別のHttpClientの呼び出し部分に処理を追加する必要はありません。

builder.Services.AddOpenTelemetryTracing((builder) => builder
        .AddAspNetCoreInstrumentation()
        .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService("Hello-Otel").AddAttributes(tags))
        //以下1行を追加する
        .AddHttpClientInstrumentation()
        .AddOtlpExporter(options => 
        {
            options.Endpoint = new Uri("https://otlp.nr-data.net:4317/");
            options.Headers = $"api-key={Environment.GetEnvironmentVariable("OTEL_API_KEY")}";
        })
    );

すると、/externalのエンドポイントは次のようにトレースが記録されます。HttpClientによる通信処理が1つの子スパンとして記録されています。これにより、全体の処理(親スパン)のうち、外部通信でどれだけかかっているかがわかります。また、レスポンスのステータスコードなどの情報がhttp.ではじまる属性として記録されています。

一方、external/error のエンドポイントは次のようにトレースが記録されます。通信処理が子スパンとして記録された上で、スパンの状態をエラーとして記録しているため赤く表示されています。

さて、子スパンはエラーとして記録されていますが、親スパンの側はエラーとしては記録されていません。これは外部通信処理がエラーであっても、必ずしも親スパンの状態がエラーになるべきではないからです。通信処理でエラーが発生した場合に親スパンもエラーとして記録したい場合、前回の記事で紹介した方法で記録することになります。

app.MapGet("/external/error", async () =>
{
    var client = new HttpClient();
    var req = await client.GetAsync("http://httpbin.org/status/502");
    try
    {
        var res = await req.EnsureSuccessStatusCode().Content.ReadAsStringAsync();
        Console.WriteLine(res);
    }
    catch (Exception e)
    {
        var activity = Activity.Current;
        activity?.SetTag("otel.status_code", "ERROR");
        activity?.SetTag("otel.status_description", "required service is down.");
        activity?.RecordException(e);
    }
});

これで親スパンもエラーとして記録されるようになります。