銀の光と碧い空

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

OpenTelemetry .NETを理解する (8) 手動でのトレースの接続例: Azure Service Busを経由したアプリ間でトレースをつなげる

複数サービス間での分散トレースは、必要な情報をサービス間で伝搬するContext Propagationによって実現されています。

opentelemetry.io

HTTPでサービスを呼び出している場合、HTTPヘッダーを利用して伝搬させることがほとんどで、最近になってW3C Trace Contextという規格で標準化が進められています。

www.w3.org

それ以外の方法、たとえばService Busなどを介している場合、トレースをつなげるためにはContext Propagationをこちらで実装する必要があります。ただ、Service Busなどのツール・サービスによってはツール・サービス側が提供していることもあり、今回はその一例としてAzure Service Busを使った例を試してみました。

Azure Service Busがどのようなしくみを提供しているかについてはドキュメントがあります。

learn.microsoft.com

ドキュメントによると、トレースをつなげるのに必要な情報(Context)としてW3C Trace Contextのtraceparentヘッダーを利用しているとあります。具体的には、<version>-<trace id>-<parent id>-<trace flags> というフォーマットです。例えば 00-182984d0d8c4fa391e63fcf168413636-797cf612be994b1c-00 という値があったとき、versionは00、trace idは182984d0d8c4fa391e63fcf168413636、parent idは797cf612be994b1c、trace flagsは00となります。この値を、Service BusのメッセージのDiagnostic-Idというプロパティに格納して伝搬させます。送信側が格納する処理を、Azure Service Bus SDKを使っていれば自動で行ってくれるとのことです。

ドキュメントでは「OpenTelemetry を使用した追跡」という部分では具体的な方法が書いていないので、今回試してみました。

まず、メッセージを送るプロデューサー側はASP.NET CoreのWebアプリで、メッセージを受け取るコンシューマー側は.NET Coreのコンソールアプリケーションです。コンシューマー側のWebアプリはOpenTelemetryでの計装がセットアップされていれば、それ以上の手間が必要ありません。送信処理は次のようになりますが、これはドキュメントにあった処理をそのまま使っています。

var clientOptions = new ServiceBusClientOptions() { TransportType = ServiceBusTransportType.AmqpWebSockets };
client = new ServiceBusClient(connectionString, clientOptions);
sender = client.CreateSender(queueName);

// create a batch 
using ServiceBusMessageBatch messageBatch = await sender.CreateMessageBatchAsync();

//デバッグ用に出力(計装そのものには不要)
var activity = Activity.Current;
Console.WriteLine($"activity id: {activity?.Id}");
Console.WriteLine($"activity Trace id: {activity?.TraceId}");
Console.WriteLine($"activity Span id: {activity?.SpanId}");

for (int i = 1; i <= numOfMessages; i++)
{
    // try adding a message to the batch
    if (!messageBatch.TryAddMessage(new ServiceBusMessage($"Message {i}: {MessageBody}")))
    {
        // if it is too large for the batch
        throw new Exception($"The message {i} is too large to fit in the batch.");
    }
}

try
{
    await sender.SendMessagesAsync(messageBatch);
    Console.WriteLine($"A batch of {numOfMessages} messages has been published to the queue.");
}
finally
{
    await sender.DisposeAsync();
    await client.DisposeAsync();
}

受信側はいままで紹介していないコンソールアプリでのOpenTelemetryの計装になるのですべてのコードを載せておきます。tracerProvider を作る部分はASP.NET Coreの場合とほぼ同じですが、ActivitySourceを生成し、インスタンスを保持したうえで、トレースの計測を行う部分でActivitySourceからActivityを生成・起動する必要があります。今回のように親SpanのIDを渡したい場合は引数で渡すことができます。

using Azure.Messaging.ServiceBus;
using OpenTelemetry.Resources;
using OpenTelemetry;
using System.Diagnostics;
using OpenTelemetry.Trace;
using OpenTelemetry.Exporter;
using System.Reflection;

//Service Busへの接続文字列
var connectionString = "<replace_your_conncetion_string>";

//Service Bus queueの名前
var queueName = "<replace_your_queue_name>";

ServiceBusClient client;
ServiceBusProcessor processor;

var serviceName = "OpenTelemetryLabs.AzureIntegrations.Console";
var assemblyVersion = Assembly.GetExecutingAssembly().GetName().Version?.ToString() ?? "unknown";
Action<ResourceBuilder> configureResource = r => r.AddService(
    serviceName, serviceVersion: assemblyVersion, serviceInstanceId: Environment.MachineName);

using var tracerProvider = Sdk.CreateTracerProviderBuilder()
    .AddSource(serviceName)
    .ConfigureResource(configureResource)
        .AddOtlpExporter(opt =>
        {
            //OTLPのエクスポート先の指定
        })
    .Build();

var MyActivitySource = new ActivitySource(serviceName);

var clientOptions = new ServiceBusClientOptions() { TransportType = ServiceBusTransportType.AmqpWebSockets };
client = new ServiceBusClient(connectionString, clientOptions);

processor = client.CreateProcessor(queueName, new ServiceBusProcessorOptions());

try
{
    processor.ProcessMessageAsync += ProcessMessageAsync;

    processor.ProcessErrorAsync += (args) =>
    {
        Console.WriteLine(args.Exception.ToString());
        return Task.CompletedTask;
    };


    while (true)
    {
        Console.WriteLine("Starting the receiver...");
        await processor.StartProcessingAsync();
        await Task.Delay(TimeSpan.FromSeconds(1));
        Console.WriteLine("Stopping the receiver...");
        await processor.StopProcessingAsync();
        Console.WriteLine("Stopped receiving messages. Waiting 60 seconds.");
        await Task.Delay(TimeSpan.FromSeconds(60));
    }
}
finally
{
    await processor.DisposeAsync();
    await client.DisposeAsync();
}

async Task ProcessMessageAsync(ProcessMessageEventArgs args)
{
    string body = args.Message.Body.ToString();
    //メッセージの本文
    Console.WriteLine($"Received: {body}");
    if (args.Message.ApplicationProperties.TryGetValue("Diagnostic-Id", out var objectId) && objectId is string diagnosticId)
    {
        //デバッグ用にDiagnosticId(traceparentヘッダー)の値を出力
        Console.WriteLine($"DiagnosticId: {diagnosticId}");
        //traceparentヘッダーを送信したSpanを親のスパンとして子スパンを開始
        using var activity = MyActivitySource.StartActivity("ProcessMessageAsync", ActivityKind.Consumer, parentId: diagnosticId);
        //デバッグ用に子スパンの情報を出力
        Console.WriteLine($"activity id: {activity?.Id}");
        Console.WriteLine($"activity Trace id: {activity?.TraceId}");
        Console.WriteLine($"activity Span id: {activity?.SpanId}");
        Console.WriteLine($"activity Parent id: {activity?.ParentId}");
        //タグを追加
        activity?.SetTag("message", body);

        await Task.Delay(1000);
        await args.CompleteMessageAsync(args.Message);
    }
}

さて、実際に実行するとプロデューサー側ではこのようにActivityのTrace IDとSpan IDが出力されます。

activity id: 00-59ed36599d26220d1362c2ac04e66cb3-394930dbfcb529b3-01
activity Trace id: 59ed36599d26220d1362c2ac04e66cb3
activity Span id: 394930dbfcb529b3

すると、コンシューマー側ではこのように出力されます。DiagnosticIdで上と同じ値が渡ってきており、これを親としてSpanを作成するとTrace Idは同じで、Span Idが別のものになっています。また、Parent Idが設定されていることも確認できます。

DiagnosticId: 00-59ed36599d26220d1362c2ac04e66cb3-394930dbfcb529b3-01
activity id: 00-59ed36599d26220d1362c2ac04e66cb3-0066bfbb9bc123a8-01
activity Trace id: 59ed36599d26220d1362c2ac04e66cb3
activity Span id: 0066bfbb9bc123a8
activity Parent id: 00-59ed36599d26220d1362c2ac04e66cb3-394930dbfcb529b3-01

これで目的は達成できましたが、最後にオブザーバビリティバックエンドでどのように見えるかの一例をあげます。上で出力されたTrace Idをもつ1つのトレースとして表示されます。また、プロデューサー側は1回の処理=1つのトレースで3つのメッセージを送信するため、3つのコンシューマー側のスパンが確認できます。

プロデューサー側のSpanのIdも確認でき、

コンシューマー側のParent Idに設定されていることがわかります。

なお、コンシューマー側のSpanが完了するまでがトレースの継続時間となるため、場合によっては非常に長くなる場合があります。サービスによっては1つのトレースでつなげるのではなく、複数のトレースに共通の属性の値としてもたせておき、必要に応じて関連付けを検索できるようにしたほうがいい場合もあります。また、複数の異なるプロデューサーのメッセージを、1つのコンシューマーで処理する場合、複数の親をもった子スパンを現在のOpenTelemetryの分散トレースでは表現できないため、複数のトレースとして表現する必要があります。

Visual Studioからdocker composeを使っていて、突然「unexpected character "»" in variable name near "\ufeff" 」というエラーが出たら

"\ufeff" はかの有名なByte Order Mark(BOM)です。 現状のdocker composeでは.envファイルなどにBOMがあると正しく処理ができずエラーになるようです。

github.com

Visual Studio使わない場合でも起こりえると思いますが、Visual Studioを使った docker composeの起動で発生しました。この図のようにdocker compose用のプロジェクトに.envファイルを配置できるのですが、

最初作成したときは動作していたものの、一度Visual Studioを閉じて、開き直したタイミングでタイトルのエラーが出ました。どうやらBOM付UTF-8で保存されてしまったようです。

BOMなしに変更するには、Visual Studioの「ファイル」メニューで名前を付けて保存を選び、同じファイル名で上書き保存のオプションでエンコード付きで保存を選び、

Unicode (UTF-8シグネチャなし)を選び保存します。

以上で動作するようになりました。

インサイドWindows第7版(下)第10章の書評

今回、インサイドWindows第7版(下)を山内さんより献本いただきました。全部読了する前に、最も興味を惹かれた第10章「管理、診断、トレース」を読んで、書評を掲載します。なお、ご自身のブログにて目次が公開されています。

yamanxworld.blogspot.com

この章はレジストリからはじまりWindowsサービス、タスクスケジューラー、WMI、ETW、DTraceと説明がつづいていきます。レジストリから始まるのは、残りの機能の紹介にレジストリが必要だからですが、いきなり11章読んでも理解できたように、必要なところを読み進めて、必要に応じて参照されている節を読めば理解できる構成になっていました。

11章はまずレジストリに関する説明から始まります。レジストリに関しては以前まとめたことがあるのですが、やはりこのとき調べた情報以上に網羅されています。

tech.tanaka733.net

tech.tanaka733.net

まず、レジストリを参照・変更できるツールの話からはじまり、使用法、データ型、論理構造と進んでいきます。それを操作するには何を使うのか、何のために使うのか、を説明したあとに、詳細の説明をしていくという流れで、丁寧に理解を深めていくことができました。

また、いたるところで実習というのが用意されていて、例えばレジストリでは、特定のプロセスが利用しているレジストリキーを特定するという手順が紹介されています。今読んだこの機能を実際に使うとできるんだろうというところを実際に試すことができます。

ちなみに、ここまでが「10.1.8 Process Monitorの内部」で、レジストリについてもまだ半分程度の量です。後半はレジストリの内部構造の説明へと進んでいきます。その記述の詳細さに圧倒されました。

レジストリの次はWindowsサービスに移ります。今まで、都度必要な時に必要な知識を調べて使っていたWindowsサービスですが、この節で体系立てて知ることができました。Windowsサービスの前にレジストリの説明がしてあるのは、おそらくWindowsサービスがレジストリを大いに利用しているためで、どのレジストリキーにどの設定を保存しているかがまとめられています。サービスアカウントやSIDなども説明されています。網羅性があり辞書のように使える部分がありながら、学習用として読み進めて理解を深めることができると感じました。

Windowsサービスでは、共有サービスプロセスについても説明されており、プロセス一覧でよく見る「Svchost」とは何ぞやみたいな疑問にも説明できるようになります。

タスクスケジュラーやWMI、ETWと進むについて、アーキテクチャ図やデータ構造などを表現する図が多いことに気づきました。詳細な説明に加えて図があるため、とてもわかりやすくなっています。ETWについては10年近く前に利用していましたが、そのとき出ていたはずの第6版にはすでにETWの章があったらしいので、読めばよかったなあと後悔しています。(当時、インサイドWindowsを読むという発想が出てこなかった)

tech.tanaka733.net

第7版で追加された項目もあります(最初のブログ記事に記載されています)が、第10章の中で追加された中ではDTraceが興味を惹かれました。もう少しいろいろ触ってみたいと思います。

今回、翻訳本の書評なのですが、これだけの詳細な文章や図などを日本語で読めるということがまずうれしいです。外資系企業に勤めるものとして他人事ではないのですが、概要レベルはともかき、詳細な技術情報となるとどうしても翻訳コストがかかって英語のみ、あるいは機械翻訳ベースの提供となってしまう点があります。特にもともとアプリケーションエンジニアをやっていて、Windows OSそのものにはそこまで詳しくない私としては、この内容を英語で読むとかなり時間がかかるはずなので、非常に助かります。 また、訳注がついており、原文の翻訳だけだと理解しづらかったり試しづらかったりする箇所の補足がされています。

積読も多いし、個人的な事情でいろいろ忙しい年になっていますが、この本はきちんと時間をとって一通り読み込もうを思っています。