DiagnosticSource es un conjunto simple pero muy útil de API (disponible en el paquete NuGet System.Diagnostics.DiagnosticSource ), que, por un lado, permite que varias bibliotecas envíen eventos con nombre sobre su trabajo y, por otro lado, permite que las aplicaciones se suscriban a estos eventos y procesos ellos.
Cada uno de estos eventos contiene información adicional (carga útil), y dado que los eventos se procesan en el mismo proceso que el envío, esta información puede contener casi cualquier objeto sin la necesidad de serialización / deserialización.
DiagnosticSource ya se usa en AspNetCore, EntityFrameworkCore, HttpClient y SqlClient, lo que realmente brinda a los desarrolladores la capacidad de interceptar solicitudes http entrantes / salientes, solicitudes de bases de datos, objetos de acceso como HttpContext , DbConnection , DbCommand , HttpRequestMessage y muchos otros objetos si es necesario.
Decidí dividir mi historia sobre DiagnosticSource en dos artículos. En este artículo, analizaremos el principio del funcionamiento del mecanismo con un ejemplo simple, y en el siguiente hablaré sobre los eventos que existen en .NET que pueden procesarse con él y mostraré algunos ejemplos de su uso en OZON.ru.
Ejemplo
Para comprender mejor cómo funciona DiagnosticSource, considere un pequeño ejemplo de interceptar consultas de bases de datos. Imagine que tenemos una aplicación de consola simple que realiza una solicitud a la base de datos y muestra el resultado en la consola.
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)) {
Para simplificar, planteé SQL Server en un contenedor acoplable.
Docker Run 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
Ahora imagine que tenemos una tarea: necesitamos medir el tiempo de ejecución de todas las consultas a la base de datos usando el Stopwatch y mostrar los pares "Solicitud" - "Tiempo de ejecución" en la consola.
Por supuesto, puede simplemente envolver la llamada QuerySingleAsync código que crea e inicia la instancia del Stopwatch , la detiene después de ejecutar la consulta y muestra el resultado, pero hay varias dificultades a la vez:
- ¿Qué pasa si la aplicación tiene más de una solicitud?
- ¿Qué sucede si el código que ejecuta la solicitud ya está compilado, está conectado a la aplicación como un paquete NuGet y no tenemos forma de cambiarlo?
- ¿Qué sucede si la consulta a la base de datos no se realiza a través de Dapper, sino a través de EntityFramework, por ejemplo, y no tenemos acceso al objeto
DbCommand , ni al texto de consulta generado que realmente se ejecutará?
Intentemos resolver este problema usando DiagnosticSource.
Uso del paquete NuGet System.Diagnostics.DiagnosticSource
Lo primero que debe hacer después de conectar el paquete NuGet de System.Diagnostics.DiagnosticSource es crear una clase que maneje los eventos que nos interesan:
public sealed class ExampleDiagnosticObserver { }
Para comenzar a procesar eventos, debe crear una instancia de esta clase y registrarla como observador en el objeto estático DiagnosticListener.AllListeners (ubicado en el espacio de nombres System.Diagnostics ). Hacemos esto al comienzo de la función Main :
public static async Task Main() { var observer = new ExampleDiagnosticObserver(); IDisposable subscription = DiagnosticListener.AllListeners.Subscribe(observer); var answer = await GetAnswerAsync(); Console.WriteLine(answer); }
En este caso, el compilador nos dirá correctamente que la clase ExampleDiagnosticObserver debe implementar la IObserver<DiagnosticListener> . Vamos a implementarlo:
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() { } }
Si ejecutamos este código ahora, veremos que se mostrará lo siguiente en la consola:
SqlClientDiagnosticListener SqlClientDiagnosticListener 42
Esto significa que en algún lugar de .NET dos objetos del tipo DiagnosticListener se registran con el nombre "SqlClientDiagnosticListener" que funcionaba cuando se ejecutaba este código.
Aquí están en github.comEn realidad, hay tres de ellos, pero como no utilizamos SqlTransaction , solo dos funcionaron:
El IObserver<DiagnosticListener>.OnNext se llamará una vez al primer uso para cada instancia del DiagnosticListener que se crea en la aplicación (generalmente se crean como propiedades estáticas). Ahora acabamos de mostrar el nombre de las instancias de DiagnosticListener en la consola, pero en la práctica este método necesita verificar este nombre y, si estamos interesados en procesar eventos desde esta instancia, suscribirse a él utilizando el método Subscribe .
También quiero señalar que cuando llamamos DiagnosticListener.AllListeners.Subscribe obtendremos un objeto de subscription como resultado, que implementa la interfaz IDisposable . Llamar al método Dispose en este objeto conducirá a la cancelación de la suscripción, que debe implementarse en el IObserver<DiagnosticListener>.OnCompleted .
Implementemos el IObserver<DiagnosticListener> nuevamente:
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(); } }
Ahora el compilador nos dirá que nuestra clase ExampleDiagnosticObserver también debe implementar la IObserver<KeyValuePair<string, object>> . Aquí necesitamos implementar el IObserver<KeyValuePair<string, object>>.OnNext , que como parámetro acepta KeyValuePair<string, object> , donde la clave es el nombre del evento, y el valor es un objeto anónimo (generalmente) con parámetros arbitrarios que podemos usar a su discreción Agreguemos una implementación de esta interfaz:
public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> {
Si ahora ejecutamos el código resultante, se mostrará lo siguiente en la consola:
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
En total, veremos seis eventos. Dos de ellos se ejecutan antes y después de abrir la conexión a la base de datos, dos, antes y después de ejecutar el comando, y dos más, antes y después de cerrar la conexión a la base de datos.
Cada evento contiene un conjunto de parámetros, como OperationId , ConnectionId , Connection , Command , que generalmente se pasan como propiedades de un objeto anónimo. Puede obtener valores escritos para estas propiedades, por ejemplo, mediante la reflexión. (En la práctica, el uso de la reflexión puede no ser muy deseable. Utilizamos DynamicMethod para obtener parámetros de eventos).
Ahora estamos listos para resolver el problema inicial: medir el tiempo de ejecución de todas las solicitudes a la base de datos y mostrarlo en la consola junto con la solicitud original.
Cambie la implementación del método Write siguiente manera:
public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> {
Aquí interceptamos los eventos de inicio y finalización de la solicitud a la base de datos. Antes de ejecutar la solicitud, creamos e iniciamos el cronómetro, guardándolo en una variable del tipo AsyncLocal<Stopwatch> , para recuperarlo más tarde. Después de ejecutar la solicitud, obtenemos el cronómetro lanzado previamente, lo detenemos, obtenemos el comando ejecutado del parámetro de value través de la reflexión e imprimimos el resultado en la consola.
Si ahora ejecutamos el código resultante, se mostrará lo siguiente en la consola:
CommandText: SELECT 42; Elapsed: 00:00:00.0341357 42
Parece que ya hemos resuelto nuestro problema, pero queda un pequeño detalle. El hecho es que cuando nos suscribimos a los eventos de DiagnosticListener , comenzamos a recibir incluso aquellos eventos que no nos interesan, y dado que cada evento se envía, se crea un objeto anónimo con parámetros, esto puede crear una carga adicional en el GC.
Para evitar esta situación y decirle qué eventos de DiagnosticListener vamos a procesar, podemos especificar un delegado especial del tipo Predicate<string> al suscribirse, que toma el nombre del evento como parámetro y devuelve true si este evento debe procesarse.
IObserver<DiagnosticListener>.OnNext en nuestra clase:
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"; }
Ahora se llamará a nuestro método Write solo para los eventos "System.Data.SqlClient.WriteCommandBefore" y "System.Data.SqlClient.WriteCommandAfter" .
Uso de NuGet Package.Extensions.DiagnosticAdapter de Microsoft
Dado que los parámetros de eventos que recibimos de DiagnosticListener generalmente se pasan como un objeto anónimo, recuperarlos a través de la reflexión puede ser demasiado costoso. Afortunadamente, hay un paquete NuGet de Microsoft.Extensions.DiagnosticAdapter que puede hacer esto por nosotros, utilizando la generación de código de tiempo de ejecución desde el System.Reflection.Emit .
Para usar este paquete al suscribirse a eventos desde una instancia de DiagnosticListener lugar del método Subscribe , debe usar el método de extensión SubscribeWithAdapter . La implementación de la IObserver<KeyValuePair<string, object>> en este caso ya no es necesaria. En cambio, para cada evento que deseamos controlar, necesitamos declarar un método separado, marcándolo con el atributo DiagnosticNameAttribute (del espacio de nombres Microsoft.Extensions.DiagnosticAdapter ). Los parámetros de estos métodos serán los parámetros del evento que se está procesando.
Si reescribimos nuestra clase ExampleDiagnosticObserver usando este paquete NuGet, obtenemos el siguiente código:
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(); } }
Por lo tanto, ahora podemos medir el tiempo de ejecución de todas las consultas a la base de datos desde nuestra aplicación, prácticamente sin cambiar el código de la aplicación en sí.
Crear sus propias instancias de DiagnosticListener
Cuando utilice DiagnosticSource en la práctica, en la mayoría de los casos se suscribirá a eventos existentes. Lo más probable es que no tenga que crear sus propias instancias de DiagnosticListener y enviar sus propios eventos (solo si no está desarrollando ninguna biblioteca), por lo que no me detendré en esta sección por mucho tiempo.
Para crear su propia instancia de DiagnosticListener , deberá declararla como una variable estática en algún lugar del código:
private static readonly DiagnosticSource _myDiagnosticSource = new DiagnosticListener("MyLibraty");
Después de eso, para enviar un evento, puede usar un diseño del formulario:
if (_myDiagnosticSource.IsEnabled("MyEvent")) _myDiagnosticSource.Write("MyEvent", new { });
Para obtener más información sobre cómo crear sus propias instancias de DiagnosticListener , consulte la Guía del usuario de DiagnosticSource , que detalla las mejores prácticas para utilizar DiagnosticSource.
Conclusión
El ejemplo que examinamos es ciertamente muy abstracto y es poco probable que sea útil en un proyecto real. Pero muestra perfectamente cómo se puede usar este mecanismo para monitorear y diagnosticar sus aplicaciones.
En el próximo artículo, daré una lista de eventos que conozco que se pueden procesar a través de DiagnosticSource, y mostraré algunos ejemplos prácticos de su uso.