.NET CoreでDiagnosticSourceを使用する：練習

前の記事で 、DiagnosticSourceメカニズムについて説明し、それを使用してSqlConnectionクラスとSqlCommandクラスを介してデータベースへの要求をインターセプトし、実行時間を測定する方法を簡単な例で示しました。

現在、DiagnosticSourceは既にAspNetCore、EntityFrameworkCore、HttpClient、およびSqlClientで使用されています-それぞれが独自のイベントを送信し、それらはインターセプトおよび処理できます。

この記事では、実際にASP.NET CoreアプリケーションでDiagnosticSourceを使用する方法のいくつかの例を検討します。

• サービス間のCorrelationIDおよび転送ヘッダー
• メトリックとトレースのコレクション
• ロギング

さらに、この記事では、処理に使用でき、アプリケーションで使用できるイベントのリストを収集することにしました。また、プロジェクトでDiagnosticSourceメカニズムを使用する場合に発生する可能性のある落とし穴についても説明します。

既存のイベント

例の検討に移る前に、DiagnosticSourceを介してイベントを送信するコンポーネント、およびこれらのイベントの名前を理解する必要があります。 残念ながら、イベントの完全なリストはドキュメントのどこにも記載されておらず、GitHubのソースコードでのみ見つけることができます。

したがって、存在するイベントを理解する最も簡単な方法は、 IObserver<DiagnosticListener>およびIObserver<KeyValuePair<string, object>>インターフェイスを実装するクラスを作成し、その中のDiagnosticListenerインスタンスをサブスクライブし、アプリケーションでキャッチされるイベントを確認することです。 同様に、各イベントで送信されるパラメーターを判別できます。

タスクを簡素化するために、4つのコンポーネントの最も有用なイベント（これは完全なリストではありません）のいくつかを既に収集しています。

ちなみに、 DiagnosticSourceのイベントの命名に関する推奨事項と規則について説明しているDiagnosticSource User's Guideもあります 。

簡単に推測できるように、Microsoftはこれらの推奨事項に従わず、反対のことを行います=）（わかりました、誇張します。DiagnosticSourceユーザーガイドが登場する前に、DiagnosticSourceが.NET Coreコンポーネントで使用され始めました）

共通コード

以下で検討するすべての例は、ASP.NET Coreアプリケーションで使用されるものと想定され（これは必須ではありません）、基本クラスDiagnosticObserverBaseを使用してDiagnosticObserverBaseからイベントをサブスクライブして処理します。

このクラスは、 前回の記事の ExampleDiagnosticObserverクラスに基づいており、その操作の説明を参照できます。 イベントをサブスクライブして処理するために、このクラスはMicrosoft.Extensions.DiagnosticAdapterの NuGetパッケージのSubscribeWithAdapterメソッドを使用します 。

 public abstract class DiagnosticObserverBase : IObserver<DiagnosticListener> { private readonly List<IDisposable> _subscriptions = new List<IDisposable>(); protected abstract bool IsMatch(string name); void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener) { if (IsMatch(diagnosticListener.Name)) { var subscription = diagnosticListener.SubscribeWithAdapter(this); _subscriptions.Add(subscription); } } void IObserver<DiagnosticListener>.OnError(Exception error) { } void IObserver<DiagnosticListener>.OnCompleted() { _subscriptions.ForEach(x => x.Dispose()); _subscriptions.Clear(); } } 

特定のコンポーネントからイベントをサブスクライブするには、新しいクラスを作成し、 DiagnosticObserverBaseから継承し、サブスクライブするコンポーネントに対してtrueを返すIsMatchメソッドを再定義し、イベントを処理するメソッドを追加し、名前を指定するDiagnosticNameAttribute属性でマークする必要があります処理されたイベント。 例：

 public sealed class SomeDiagnosticObserver : DiagnosticObserverBase { protected override bool IsMatch(string name) { return name == "SomeComponent"; } [DiagnosticName("SomeEvent")] public void OnSomeEvent(/* EventParameters */) { // ... } } 

DIコンテナーのDiagnosticObserverBaseクラスに基づいてハンドラーを登録するには、 AddDiagnosticObserver拡張AddDiagnosticObserver使用します。これは、Startup.csファイルのConfigureServicesメソッドで使用されます。

 public static class DiagnosticServiceCollectionExtensions { public static void AddDiagnosticObserver<TDiagnosticObserver>( this IServiceCollection services) where TDiagnosticObserver : DiagnosticObserverBase { services.TryAddEnumerable(ServiceDescriptor .Transient<DiagnosticObserverBase, TDiagnosticObserver>()); } } 

また、DiagnosticSourceからイベントをサブスクライブするには、 Configureメソッドに次の行を追加します。

 public void Configure(IApplicationBuilder app, IHostingEnvironment env) { var diagnosticObservers = app .ApplicationServices.GetServices<DiagnosticObserverBase>(); foreach (var diagnosticObserver in diagnosticObservers) { DiagnosticListener.AllListeners.Subscribe(diagnosticObserver); } // ... app.UseMvc(); } 

おそらくこれは登録するのに最適な方法ではなく、実際には通常このような目的でIHostedServiceインターフェイスを使用しますが、例で十分です。

いくつかの落とし穴

プロジェクトでDiagnosticSourceを使用することに決めた場合は、私が詳しく説明したい非自明な点に出くわすかもしれません。

存在しないイベントのダミーハンドラが必要になる場合があります。

通常、一部のコンポーネントがその作業に関するイベントを送信する場合、イベントを送信するコードは次のとおりです。

 if (_diagnosticSource.IsEnabled("SomeEvent")) _diagnosticSource.Write("SomeEvent", new { /* parameters */ }); 

これにより、誰もイベントを処理する予定がない場合にパラメータを持つオブジェクトを作成せず、ガベージコレクションを少し節約できます。

ただし、場合によっては、サフィックスが.Startと.Stopイベントがペアになり、両方とも機能するかどうかが.Stopます。 このようなイベントを送信するコードは次のようになります。

  //  ,     . var someEventIsEnabled = _diagnosticSource.IsEnabled("SomeEvent"); if (someEventIsEnabled && _diagnosticSource.IsEnabled("SomeEvent.Start")) _diagnosticSource.Write("SomeEvent.Start", new { /* parameters */ }); // ... if (someEventIsEnabled && _diagnosticSource.IsEnabled("SomeEvent.Stop")) _diagnosticSource.Write("SomeEvent.Stop", new { /* parameters */ }); 

したがって、 SomeEvent.StopイベントとSomeEvent.Stopイベントをサブスクライブするには、 SomeEventイベントのダミーハンドラーも追加する必要があります。これは呼び出されませんが、その存在はチェックされます。

いくつかのイベントはペアになり、いくつかのトリプルは

System.Net.Http.HttpRequestOut.StartやSystem.Net.Http.HttpRequestOut.Stopなど、一部のイベントはペアになっています。 つまり、接尾辞が.Startイベントは何らかの操作の開始前に呼び出され、接尾辞が.Stopイベントは最後に呼び出されます。 この場合、操作がエラーで終了したかどうかに関係なく、最後のイベントがトリガーされることが保証されます（適切なハンドラーがある場合）。

ただし、一部のイベントはトリプルです。たとえば、 System.Data.SqlClient.WriteCommandBefore 、 System.Data.SqlClient.WriteCommandAfter 、およびSystem.Data.SqlClient.WriteCommandErrorで、最後のイベントは操作の結果に依存します。 この場合、操作が正常に完了した場合はSystem.Data.SqlClient.WriteCommandAfterイベントのみが発生し、操作中にエラーが発生した場合はSystem.Data.SqlClient.WriteCommandErrorイベントのみがSystem.Data.SqlClient.WriteCommandErrorます。

たとえば、イベントを使用して操作の時間を測定する場合、これを考慮する必要があります。 たとえば、操作の開始時にストップウォッチを開始する場合、データを失わないように2つの場所でストップウォッチを停止する必要があります。

DiagnosticSourceの例

これで、DiagnosticSourceメカニズムを実際のアプリケーションでどのように実行できるかを検討する準備がすべて整いました。

サービス間のCorrelationIDおよび転送ヘッダー

マイクロサービスの世界では、CorrelationIDという用語がよく見られます。 これは、サービスにアクセスするたびに生成される識別子であり、httpヘッダーを介してサービス間でさらに送信されます。 通常、この識別子はログに書き込まれるため、単一のトランザクションの一部として受信した複数のサービスからのメッセージをリンクできます。

ASP.NET CoreにはCorrelationId NuGetパッケージがありますが、開発者はすべての発信要求に適切なヘッダーを手動で追加する必要があるため、使用するのはあまり便利ではありません。

DiagnosticSourceを使用してCorrelationIdを実装します。 まず、識別子の保存を担当するCorrelationIdクラスを追加します。

 public static class CorrelationId { private static readonly AsyncLocal<Guid?> _current = new AsyncLocal<Guid?>(); public static Guid Current { get { var value = _current.Value; if (value == null) throw new InvalidOperationException("CorrelationId isn't assigned."); return value.Value; } set { _current.Value = value; } } } 

このクラスは、タイプAsyncLocal <T>のインスタンスを使用して、現在のCorrelationId値を格納します。これは、各リクエストに対して一意ですが、非同期コードを操作するときにThreadPoolから別のスレッドに正しく転送されます

次のステップは、DiagnosticSourceからイベントハンドラーを追加することです。これにより、着信および発信HTTP要求がインターセプトされます。 受信リクエストでは、 X-Correlation-IDヘッダーの存在を確認し、存在しない場合は、 Guid.NewGuid()介して新しい識別子を生成します。 発信リクエストでは、 CorrelationId.Currentを使用してヘッダーを追加するだけです。

 public sealed class CorrelationIdHandler : DiagnosticObserverBase { protected override bool IsMatch(string name) { return name == "Microsoft.AspNetCore" || name == "HttpHandlerDiagnosticListener"; } //   http  [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn")] public void OnHttpRequestIn() { } [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")] public void OnHttpRequestInStart(HttpContext httpContext) { //    CorrelationId    http . var headers = httpContext.Request.Headers; if (headers.TryGetValue("X-Correlation-ID", out var header)) { if (Guid.TryParse(header, out var correlationId)) { CorrelationId.Current = correlationId; return; } } //    CorrelationId. CorrelationId.Current = Guid.NewGuid(); } //   http  [DiagnosticName("System.Net.Http.HttpRequestOut")] public void OnHttpRequestOut() { } [DiagnosticName("System.Net.Http.HttpRequestOut.Start")] public void OnHttpRequestOutStart(HttpRequestMessage request) { //     http    CorrelationId var correlationId = CorrelationId.Current.ToString(); request.Headers.Add("X-Correlation-ID", correlationId); } } 

このクラスでは、 IsMatchメソッドIsMatch 、 Microsoft.AspNetCoreコンポーネント（着信HTTP要求に対応）およびHttpHandlerDiagnosticListener （発信HTTP要求に責任）からのイベントを処理することを報告します。 ヘッダーの直接処理は、 OnHttpRequestInStartおよびOnHttpRequestOutStart発生しOnHttpRequestOutStart 。

さらに、2つのダミーメソッドOnHttpRequestInとOnHttpRequestOutを追加するOnHttpRequestInありOnHttpRequestOut 。 処理中は呼び出されませんが、 StartハンドラとStopハンドラのペアを呼び出すかどうかを決定するために使用されます。 それらがなければ、これらのイベントはトリガーされません。

Startup.csファイルにハンドラーを登録するだけです。

 services.AddDiagnosticObserver<CorrelationIdHandler>(); 

実際には、1つではなく特定のプレフィックス（たとえば、「X-Api-」）を持つ複数のヘッダーを転送することも有用です。これにより、いわゆるコンテキスト伝播が実装されます。 このメカニズムを使用すると、リクエスト本体を介してこの値を明示的に渡すことなく、あるサービスの特定のキーに値を設定し、別のサービスに読み込むことができます。 上記のCorrelationIdHandlerクラスに基づいて、同様のメカニズムを簡単に実装できます。

メトリックとトレースのコレクション

メトリックとトレースは、アプリケーションの重要な部分です。 メトリックを使用すると、アプリケーションの監視とダッシュボード、およびトレースを構成して、それらのボトルネックを見つけることができます。

OZON.ruでは、 Prometheusを使用してメトリックを収集し、ASP.NET Coreサービスの場合はNuGetパッケージPrometheus.Client.AspNetCoreを使用します。

トレースを収集するには、 OpenTracingとJaegerを使用します。 （ご希望の場合は、DotNetMsk Meetut＃30での私の講演 「.NETでのOpenTracingの使用」をご覧ください）

ただし、多くの開発者は、アプリケーションをメトリックとトレースでカバーすることにあまり熱心ではありません。これは、多くの場合、追加の統一コードを記述する必要があり、「ビジネスタスク」とあまり整合性がないためです。

幸いなことに、DiagnosticSourceを通じてイベントをディスパッチするほとんどのコンポーネントはペアのイベントを送信します。最初のイベントは特定の操作の開始を示し、2番目は特定の操作の完了を示します。 これにより、たとえば、最初にストップウォッチを開始し、次に停止して特定のメトリックを与えることができます。

たとえば、すべてのコントローラーアクションの実行時間のメトリックを収集する場合、次のクラスを使用できます。

 public sealed class AspNetCoreMetricsHandler : DiagnosticObserverBase { private readonly Histogram requestDurationSeconds; public MetricsHandler(MetricFactory metricFactory) { //  ,  NuGet  Prometheus.Client. //        . requestDurationSeconds = metricFactory.CreateHistogram( "request_duration_seconds", "", labelNames: new[] {"action_name"}); } protected override bool IsMatch(string name) { return name == "Microsoft.AspNetCore"; } [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn")] public void OnHttpRequestIn() { } [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")] public void OnHttpRequestInStart(HttpContext httpContext) { //     http   . httpContext.Items["Stopwatch"] = Stopwatch.StartNew(); } [DiagnosticName("Microsoft.AspNetCore.Mvc.BeforeAction")] public void OnBeforeAction(HttpContext httpContext, ActionDescriptor actionDescriptor) { //    , //     . httpContext.Items["ActionName"] = actionDescriptor.DisplayName; } [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop")] public void OnHttpRequestInStop(HttpContext httpContext) { //     http    //      . if (!httpContext.Items.TryGetValue("Stopwatch", out object stopwatch)) return; if (!httpContext.Items.TryGetValue("ActionName", out object actionName)) actionName = "Unknown"; var duration = ((Stopwatch) stopwatch).Elapsed.TotalSeconds; requestDurationSeconds .WithLabels(actionName.ToString()) .Observe(duration); } } 

ここで、コンストラクターでPrometheus.Clientの NuGetパッケージからヒストグラムメトリックを宣言します。 このメトリックにラベル「action_name」を追加します。これにより、コントローラーのさまざまなアクションで収集されたメトリックを区別できます。

イベント処理の開始時に（ OnHttpRequestInStartメソッド）、ストップウォッチを開始してクエリの実行時間を測定します。 また、処理されているアクションの名前（ OnBeforeActionメソッド）も覚えています。 そして最後に、リクエスト（ OnHttpRequestInStopメソッド）を処理した後、 httpContext.Itemsコレクションからすべてのデータを再度取得し、メトリックに書き込みます。

MetricFactoryファイルにハンドラーとMetricFactoryインスタンスを登録するだけです。

 services.AddSingleton(Prometheus.Client.Metrics.DefaultFactory); services.AddDiagnosticObserver<AspNetCoreMetricsHandler>(); 

同様の手法を使用して、NuGet OpenTracingパッケージを使用してトレースを収集できます。

ロギング

DiagnosticSourceのもう1つの非常に便利なアプリケーションは、例外ログです。 しかし、「なぜこれが必要なのか」という疑問が生じるかもしれません。 結局のところ、コードをtry-catchブロックにラップするか、未処理のすべての例外に対して1つのグローバルハンドラーを構成することもできます。

事実、DiagnosticSourceイベントによる例外処理は、例外の理由を理解するのに役立つさまざまなオブジェクトがまだ利用可能な非常に早い段階で発生するということです。 （DiagnosticSourceでは例外の処理のみが許可されますが、それ以上の伝播は妨げられないことに注意してください）

クエリテキストとそのパラメーターをログに記録しながら、データベースにアクセスするときにすべての例外を集中的に処理するとします。 DiagnosticSourceを使用して、次のようにこれを行うことができます。

 public sealed class SqlClientLoggingHandler : DiagnosticObserverBase { private readonly ILogger<SqlClientLoggingHandler> _logger; public SqlClientLoggingHandler(ILogger<SqlClientLoggingHandler> logger) { _logger = logger; } protected override bool IsMatch(string name) { return name == "SqlClientDiagnosticListener"; } [DiagnosticName("System.Data.SqlClient.WriteCommandError")] public void OnCommandError(DbCommand command, Exception exception) { var sb = new StringBuilder(); sb.AppendLine("Command: " + command.CommandText); if (command.Parameters.Count > 0) { sb.AppendLine("Parameters: "); foreach (DbParameter parameter in command.Parameters) { sb.AppendLine($"\t{parameter.ParameterName}: {parameter.Value}"); } } _logger.LogError(exception, sb.ToString()); } } 

IsMatch , SqlClientDiagnosticListener , OnCommandError .

Startup.cs :

 services.AddDiagnosticObserver<SqlClientLoggingHandler>(); 

おわりに

DiagnosticSource. , , , DiagnosticSource, ASP.NET Core.

OZON.ru . , NuGet , , .

, , DiagnosticSource .