在.NET Core中使用DiagnosticSource：理论

DiagnosticSource是一组简单但非常有用的API（在NuGet包System.Diagnostics.DiagnosticSource中提供 ），一方面，该API允许各种库发送有关其工作的命名事件，另一方面，允许应用程序订阅这些事件和进程他们。

每个此类事件都包含其他信息（有效负载），并且由于事件是在与发送相同的过程中处理的，因此该信息几乎可以包含任何对象，而无需序列化/反序列化。

DiagnosticSource已经在AspNetCore，EntityFrameworkCore，HttpClient和SqlClient中使用，它们实际上使开发人员能够拦截传入/传出的HTTP请求，数据库请求以及诸如HttpContext ， DbConnection ， DbCommand ， HttpRequestMessage类的访问对象如有必要的对象。

我决定将有关DiagnosticSource的故事分为两篇。 在本文中，我们将通过一个简单的示例来分析该机制的工作原理， 接下来，我将讨论.NET中存在的可以使用它处理的事件，并展示一些在OZON.ru中使用它的示例。

例子

为了更好地了解DiagnosticSource的工作方式，请考虑一个拦截数据库查询的小例子。 假设我们有一个简单的控制台应用程序，它向数据库发出请求并在控制台中显示结果。

 public static class Program { public const string ConnectionString = @"Data Source=localhost;Initial Catalog=master;User ID=sa;Password=Password12!;"; public static async Task Main() { var answer = await GetAnswerAsync(); Console.WriteLine(answer); } public static async Task<int> GetAnswerAsync() { using (var connection = new SqlConnection(ConnectionString)) { // using Dapper return await connection.QuerySingleAsync<int>("SELECT 42;"); } } } 

为简单起见，我在Docker容器中提出了SQL Server。

 docker run --rm --detach --name mssql-server \ --publish 1433:1433 \ --env ACCEPT_EULA=Y \ --env SA_PASSWORD=Password12! \ mcr.microsoft.com/mssql/server:2017-latest 

现在，假设我们有一个任务：我们需要使用Stopwatch测量对数据库的所有查询的执行时间，并在控制台中显示“请求”-“运行时”对。

当然，您可以QuerySingleAsync创建和启动Stopwatch实例的代码包装QuerySingleAsync调用QuerySingleAsync在执行查询后停止它并显示结果，但是同时存在一些困难：

• 如果应用程序有多个请求怎么办？
• 如果执行请求的代码已被编译，并作为NuGet包连接到应用程序，而我们无法更改它，该怎么办？
• 如果对数据库的查询不是通过Dapper而是通过EntityFramework进行的，并且我们无权访问DbCommand对象或将实际执行的生成查询文本，该怎么办？

让我们尝试使用DiagnosticSource解决此问题。

使用NuGet System.Diagnostics.DiagnosticSource包

连接System.Diagnostics.DiagnosticSource的NuGet包后，要做的第一件事是创建一个类来处理我们感兴趣的事件：

 public sealed class ExampleDiagnosticObserver { } 

为了开始处理事件，您需要创建此类的实例，并将其注册为静态对象DiagnosticListener.AllListeners （位于System.Diagnostics命名空间中）中的观察者。 我们在Main函数的开始就这样做：

 public static async Task Main() { var observer = new ExampleDiagnosticObserver(); IDisposable subscription = DiagnosticListener.AllListeners.Subscribe(observer); var answer = await GetAnswerAsync(); Console.WriteLine(answer); } 

在这种情况下，编译器将正确地告诉我们ExampleDiagnosticObserver类应实现IObserver<DiagnosticListener>接口。 让我们实现它：

 public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener> { void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener) { Console.WriteLine(diagnosticListener.Name); } void IObserver<DiagnosticListener>.OnError(Exception error) { } void IObserver<DiagnosticListener>.OnCompleted() { } } 

如果我们现在运行此代码，我们将看到以下内容将显示在控制台中：

 SqlClientDiagnosticListener SqlClientDiagnosticListener 42 

这意味着在.NET中的某个地方，使用名称"SqlClientDiagnosticListener"注册了DiagnosticListener类型的两个对象，该对象在执行此代码时起作用。

IObserver<DiagnosticListener>.OnNext 在首次使用在应用程序中创建的DiagnosticListener每个实例时就会被调用一次 （通常它们是作为静态属性创建的）。 现在，我们仅在控制台中显示了DiagnosticListener实例的名称，但是实际上，此方法需要检查此名称，并且，如果我们对处理来自该实例的事件感兴趣，请使用Subscribe方法进行Subscribe 。

我还想指出，当我们调用DiagnosticListener.AllListeners.Subscribe将得到一个subscription对象，该对象实现了IDisposable接口。 在此对象上调用Dispose方法将导致取消订阅，该订阅必须在IObserver<DiagnosticListener>.OnCompleted 。

让我们再次实现IObserver<DiagnosticListener> ：

 public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener> { private readonly List<IDisposable> _subscriptions = new List<IDisposable>(); void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener) { if (diagnosticListener.Name == "SqlClientDiagnosticListener") { var subscription = diagnosticListener.Subscribe(this); _subscriptions.Add(subscription); } } void IObserver<DiagnosticListener>.OnError(Exception error) { } void IObserver<DiagnosticListener>.OnCompleted() { _subscriptions.ForEach(x => x.Dispose()); _subscriptions.Clear(); } } 

现在，编译器将告诉我们， ExampleDiagnosticObserver类也应实现IObserver<KeyValuePair<string, object>>接口。 在这里，我们需要实现IObserver<KeyValuePair<string, object>>.OnNext ，该IObserver<KeyValuePair<string, object>>.OnNext作为参数接受KeyValuePair<string, object> ，其中键是事件的名称，值是一个匿名对象（通常），它带有我们可以使用的任意参数自行决定。 让我们添加此接口的实现：

 public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> { // IObserver<DiagnosticListener> implementation // ... void IObserver<KeyValuePair<string, object>>.OnNext(KeyValuePair<string, object> pair) { Write(pair.Key, pair.Value); } void IObserver<KeyValuePair<string, object>>.OnError(Exception error) { } void IObserver<KeyValuePair<string, object>>.OnCompleted() { } private void Write(string name, object value) { Console.WriteLine(name); Console.WriteLine(value); Console.WriteLine(); } } 

如果现在运行结果代码，则控制台中将显示以下内容：

 System.Data.SqlClient.WriteConnectionOpenBefore { OperationId = 3da1b5d4-9ce1-4f28-b1ff-6a5bfc9d64b8, Operation = OpenAsync, Connection = System.Data.SqlClient.SqlConnection, Timestamp = 26978341062 } System.Data.SqlClient.WriteConnectionOpenAfter { OperationId = 3da1b5d4-9ce1-4f28-b1ff-6a5bfc9d64b8, Operation = OpenAsync, ConnectionId = 84bd0095-9831-456b-8ebc-cb9dc2017368, Connection = System.Data.SqlClient.SqlConnection, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 26978631500 } System.Data.SqlClient.WriteCommandBefore { OperationId = 5c6d300c-bc49-4f80-9211-693fa1e2497c, Operation = ExecuteReaderAsync, ConnectionId = 84bd0095-9831-456b-8ebc-cb9dc2017368, Command = System.Data.SqlClient.SqlComman d } System.Data.SqlClient.WriteCommandAfter { OperationId = 5c6d300c-bc49-4f80-9211-693fa1e2497c, Operation = ExecuteReaderAsync, ConnectionId = 84bd0095-9831-456b-8ebc-cb9dc2017368, Command = System.Data.SqlClient.SqlComman d, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 26978709490 } System.Data.SqlClient.WriteConnectionCloseBefore { OperationId = 3f6bfd8f-e5f6-48b7-82c7-41aeab881142, Operation = Close, ConnectionId = 84bd0095-9831-456b-8ebc-cb9dc2017368, Connection = System.Data.SqlClient.SqlConnection, Stat istics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 26978760625 } System.Data.SqlClient.WriteConnectionCloseAfter { OperationId = 3f6bfd8f-e5f6-48b7-82c7-41aeab881142, Operation = Close, ConnectionId = 84bd0095-9831-456b-8ebc-cb9dc2017368, Connection = System.Data.SqlClient.SqlConnection, Stat istics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 26978772888 } 42 

总共，我们将看到六个事件。 其中两个在打开与数据库的连接之前和之后执行，两个在命令执行之前和之后，另外两个在关闭与数据库的连接之前和之后执行。

每个事件都包含一组参数，例如OperationId ， ConnectionId ， Connection ， Command ，通常作为匿名对象的属性传递。 您可以获取这些属性的类型化值，例如，使用反射。 （实际上，使用反射可能不是很理想。我们使用DynamicMethod来获取事件参数。）

现在，我们准备解决最初的问题-测量对数据库的所有请求的执行时间，并将其与原始请求一起显示在控制台中。

更改Write方法的实现，如下所示：

 public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> { // IObserver<DiagnosticListener> implementation // ... // IObserver<KeyValuePair<string, object>> implementation // ... private readonly AsyncLocal<Stopwatch> _stopwatch = new AsyncLocal<Stopwatch>(); private void Write(string name, object value) { switch (name) { case "System.Data.SqlClient.WriteCommandBefore": { //           _stopwatch.Value = Stopwatch.StartNew(); break; } case "System.Data.SqlClient.WriteCommandAfter": { //           var stopwatch = _stopwatch.Value; stopwatch.Stop(); var command = GetProperty<SqlCommand>(value, "Command"); Console.WriteLine($"CommandText: {command.CommandText}"); Console.WriteLine($"Elapsed: {stopwatch.Elapsed}"); Console.WriteLine(); break; } } } private static T GetProperty<T>(object value, string name) { return (T) value.GetType() .GetProperty(name) .GetValue(value); } } 

在这里，我们截取到数据库的请求的开始和结束事件。 在执行请求之前，我们创建并启动秒表，将其保存在AsyncLocal<Stopwatch>的变量中，以便稍后将其取回。 执行完请求后，我们得到了先前启动的秒表，将其停止，通过反射从value参数中获取已执行的命令，并将结果打印到控制台。

如果现在运行结果代码，则控制台中将显示以下内容：

 CommandText: SELECT 42; Elapsed: 00:00:00.0341357 42 

看来我们已经解决了问题，但还有一个小细节。 事实是，当我们订阅DiagnosticListener事件时，我们甚至从中开始接收那些我们不感兴趣的事件，并且由于向每个事件发送了带有参数的匿名对象，因此这会给GC造成额外的负担。

为了避免这种情况并告诉您我们将要处理DiagnosticListener哪些事件，我们可以在订阅时指定Predicate<string>类型的特殊委托，该委托将事件的名称作为参数，如果应该处理此事件，则返回true 。

IObserver<DiagnosticListener>.OnNext ：

 void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener) { if (diagnosticListener.Name == "SqlClientDiagnosticListener") { var subscription = diagnosticListener.Subscribe(this, IsEnabled); _subscriptions.Add(subscription); } } private bool IsEnabled(string name) { return name == "System.Data.SqlClient.WriteCommandBefore" || name == "System.Data.SqlClient.WriteCommandAfter"; } 

现在，仅对事件"System.Data.SqlClient.WriteCommandBefore"和"System.Data.SqlClient.WriteCommandAfter"调用我们的Write方法。

使用Microsoft的NuGet Package.Extensions.DiagnosticAdapter

由于我们通常从DiagnosticListener接收到的事件参数是作为匿名对象传递的，因此通过反射检索它们可能太昂贵了。 幸运的是，有一个Microsoft.Extensions.DiagnosticAdapter NuGet包可以使用从System.Reflection.Emit生成的运行时代码来为我们完成此操作。

为了从DiagnosticListener实例而不是Subscribe方法订阅事件时使用此程序包，必须使用SubscribeWithAdapter扩展方法。 在这种情况下，不再需要实现IObserver<KeyValuePair<string, object>>接口。 而是，对于我们要处理的每个事件，我们需要声明一个单独的方法，并使用DiagnosticNameAttribute属性（从Microsoft.Extensions.DiagnosticAdapter命名空间）对其进行标记。 这些方法的参数将是正在处理的事件的参数。

如果使用此NuGet包重写ExampleDiagnosticObserver类，则会得到以下代码：

 public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener> { private readonly List<IDisposable> _subscriptions = new List<IDisposable>(); void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener) { if (diagnosticListener.Name == "SqlClientDiagnosticListener") { 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(); } private readonly AsyncLocal<Stopwatch> _stopwatch = new AsyncLocal<Stopwatch>(); [DiagnosticName("System.Data.SqlClient.WriteCommandBefore")] public void OnCommandBefore() { _stopwatch.Value = Stopwatch.StartNew(); } [DiagnosticName("System.Data.SqlClient.WriteCommandAfter")] public void OnCommandAfter(DbCommand command) { var stopwatch = _stopwatch.Value; stopwatch.Stop(); Console.WriteLine($"CommandText: {command.CommandText}"); Console.WriteLine($"Elapsed: {stopwatch.Elapsed}"); Console.WriteLine(); } } 

因此，我们现在可以测量从我们的应用程序对数据库的所有查询的执行时间，而实际上无需更改应用程序本身的代码。

创建自己的DiagnosticListener实例

在实践中使用DiagnosticSource时，大多数情况下，您将订阅现有事件。 您很可能不必创建自己的DiagnosticListener实例并发送您自己的事件（仅当您不开发任何库时），因此我不会在此部分上进行过多介绍。

要创建自己的DiagnosticListener实例，您需要在代码中的某处将其声明为静态变量：

 private static readonly DiagnosticSource _myDiagnosticSource = new DiagnosticListener("MyLibraty"); 

之后，要发送事件，可以使用以下形式的设计：

 if (_myDiagnosticSource.IsEnabled("MyEvent")) _myDiagnosticSource.Write("MyEvent", new { /* parameters */ }); 

有关创建自己的DiagnosticListener实例的更多信息，请参阅《 DiagnosticSource用户指南》 ，其中详细介绍了使用DiagnosticSource的最佳实践。

结论

我们研究的示例当然非常抽象，不太可能在实际项目中有用。 但是，它完美地说明了如何使用这种机制来监视和诊断您的应用程序。

在下一篇文章中，我将提供可以通过DiagnosticSource处理的我所知道的事件列表，并显示一些使用它的实际示例。