DiagnosticSource é um conjunto de APIs simples, mas muito útil (disponível no pacote NuGet System.Diagnostics.DiagnosticSource ), que, por um lado, permite que várias bibliotecas enviem eventos nomeados sobre seu trabalho e, por outro lado, permite que aplicativos se inscrevam nesses eventos e processos eles.
Cada um desses eventos contém informações adicionais (carga útil) e, como os eventos são processados no mesmo processo do envio, essas informações podem conter quase todos os objetos sem a necessidade de serialização / desserialização.
DiagnosticSource já é usado no AspNetCore, EntityFrameworkCore, HttpClient e SqlClient, o que realmente oferece aos desenvolvedores a capacidade de interceptar solicitações HTTP de entrada / saída, solicitações de banco de dados, objetos de acesso como HttpContext
, DbConnection
, DbCommand
, HttpRequestMessage
e muitos outros objetos, se necessário.
Decidi dividir minha história sobre o DiagnosticSource em dois artigos. Neste artigo, analisaremos o princípio da operação do mecanismo com um exemplo simples e, a seguir , falarei sobre eventos existentes no .NET que podem ser processados usando-o e mostraremos alguns exemplos de seu uso no OZON.ru.
Exemplo
Para entender melhor como o DiagnosticSource funciona, considere um pequeno exemplo de interceptação de consultas ao banco de dados. Imagine que temos um aplicativo de console simples que faz uma solicitação ao banco de dados e exibe o resultado no console.
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, criei o SQL Server em um contêiner de docker.
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
Agora imagine que temos uma tarefa: precisamos medir o tempo de execução de todas as consultas no banco de dados usando o Stopwatch
e exibir os pares "Request" - "Runtime" no console.
Obviamente, você pode simplesmente QuerySingleAsync
chamada QuerySingleAsync
código que cria e inicia a instância do Stopwatch
, para após a execução da consulta e exibe o resultado, mas existem várias dificuldades ao mesmo tempo:
- E se o aplicativo tiver mais de uma solicitação?
- E se o código que executa a solicitação já estiver compilado, estiver conectado ao aplicativo como um pacote NuGet e não tivermos como alterá-lo?
- E se a consulta ao banco de dados não for feita pelo Dapper, mas pelo EntityFramework, por exemplo, e não tivermos acesso ao objeto
DbCommand
ou ao texto da consulta gerado que será realmente executado?
Vamos tentar resolver esse problema usando o DiagnosticSource.
Usando o pacote NuGet System.Diagnostics.DiagnosticSource
A primeira coisa a fazer depois de conectar o pacote NuGet do System.Diagnostics.DiagnosticSource é criar uma classe que manipulará os eventos de seu interesse:
public sealed class ExampleDiagnosticObserver { }
Para iniciar o processamento de eventos, é necessário criar uma instância dessa classe e registrá-la como um observador no objeto estático DiagnosticListener.AllListeners
(localizado no espaço para nome System.Diagnostics
). Fazemos isso no início da função Main
:
public static async Task Main() { var observer = new ExampleDiagnosticObserver(); IDisposable subscription = DiagnosticListener.AllListeners.Subscribe(observer); var answer = await GetAnswerAsync(); Console.WriteLine(answer); }
Nesse caso, o compilador nos dirá com razão que a classe ExampleDiagnosticObserver
deve implementar a interface IObserver<DiagnosticListener>
. Vamos implementá-lo:
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() { } }
Se executarmos este código agora, veremos que o seguinte será exibido no console:
SqlClientDiagnosticListener SqlClientDiagnosticListener 42
Isso significa que em algum lugar do .NET são registrados dois objetos do tipo DiagnosticListener
com o nome "SqlClientDiagnosticListener"
que funcionaram quando esse código foi executado.
Aqui estão eles no github.comNa verdade, existem três deles, mas como não usamos o SqlTransaction
, apenas dois funcionaram:
O IObserver<DiagnosticListener>.OnNext
será chamado uma vez no primeiro uso para cada instância do DiagnosticListener
criada no aplicativo (geralmente elas são criadas como propriedades estáticas). Agora, apenas exibimos o nome das instâncias DiagnosticListener
no console, mas, na prática, esse método precisa verificar esse nome e, se estivermos interessados em processar eventos a partir dessa instância, assine-o usando o método Subscribe
.
Também quero observar que, quando chamamos DiagnosticListener.AllListeners.Subscribe
obteremos um objeto de subscription
como resultado, o que implementa a interface IDisposable
. Chamar o método Dispose
nesse objeto levará à remoção da assinatura, que deve ser implementada no IObserver<DiagnosticListener>.OnCompleted
.
Vamos implementar o IObserver<DiagnosticListener>
novamente:
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(); } }
Agora o compilador nos dirá que nossa classe ExampleDiagnosticObserver
também deve implementar a IObserver<KeyValuePair<string, object>>
. Aqui precisamos implementar o IObserver<KeyValuePair<string, object>>.OnNext
, que como parâmetro aceita KeyValuePair<string, object>
, em que a chave é o nome do evento e o valor é um objeto anônimo (geralmente) com parâmetros arbitrários que podemos usar a seu critério. Vamos adicionar uma implementação desta interface:
public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> {
Se agora executarmos o código resultante, o seguinte será exibido no console:
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
No total, veremos seis eventos. Dois deles são executados antes e depois de abrir a conexão com o banco de dados, dois - antes e depois da execução do comando e mais dois - antes e depois de fechar a conexão com o banco de dados.
Cada evento contém um conjunto de parâmetros, como OperationId
, ConnectionId
, Connection
, Command
, que geralmente são passados como propriedades de um objeto anônimo. Você pode obter valores digitados para essas propriedades, por exemplo, usando reflexão. (Na prática, o uso de reflexão pode não ser muito desejável. Usamos DynamicMethod para obter parâmetros de evento.)
Agora estamos prontos para resolver o problema inicial - para medir o tempo de execução de todas as solicitações ao banco de dados e exibi-lo no console junto com a solicitação original.
Altere a implementação do método Write
seguinte maneira:
public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>> {
Aqui, interceptamos os eventos de início e fim da solicitação no banco de dados. Antes de executar a solicitação, criamos e iniciamos o cronômetro, salvando-o em uma variável do tipo AsyncLocal<Stopwatch>
, para recuperá-lo mais tarde. Após executar a solicitação, obtemos o cronômetro lançado anteriormente, paramos, obtemos o comando executado a partir do parâmetro value
via reflexão e imprimimos o resultado no console.
Se agora executarmos o código resultante, o seguinte será exibido no console:
CommandText: SELECT 42; Elapsed: 00:00:00.0341357 42
Parece que já resolvemos nosso problema, mas resta um pequeno detalhe. O fato é que, quando DiagnosticListener
eventos DiagnosticListener
, começamos a receber dele mesmo os eventos que não são interessantes para nós e, como cada evento é enviado, um objeto anônimo com parâmetros é criado, isso pode criar uma carga extra no GC.
Para evitar essa situação e informar quais eventos do DiagnosticListener
vamos processar, podemos especificar um delegado especial do tipo Predicate<string>
ao se inscrever, que aceita o nome do evento como parâmetro e retorna true
se esse evento for processado.
IObserver<DiagnosticListener>.OnNext
em nossa classe:
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"; }
Agora, nosso método Write
será chamado apenas para os eventos "System.Data.SqlClient.WriteCommandBefore"
e "System.Data.SqlClient.WriteCommandAfter"
.
Usando o NuGet Package.Extensions.DiagnosticAdapter da Microsoft
Como os parâmetros de evento que recebemos do DiagnosticListener
geralmente são passados como um objeto anônimo, recuperá-los através da reflexão pode ser muito caro. Felizmente, existe um pacote NuGet do Microsoft.Extensions.DiagnosticAdapter que pode fazer isso por nós, usando a geração de código de tempo de execução no System.Reflection.Emit
.
Para usar este pacote ao assinar eventos de uma instância do DiagnosticListener
vez do método Subscribe
, você deve usar o método de extensão SubscribeWithAdapter
. A implementação da IObserver<KeyValuePair<string, object>>
nesse caso não é mais necessária. Em vez disso, para cada evento que desejamos manipular, precisamos declarar um método separado, marcando-o com o atributo DiagnosticNameAttribute
(no espaço de nome Microsoft.Extensions.DiagnosticAdapter
). Os parâmetros desses métodos serão os parâmetros do evento que está sendo processado.
Se reescrevermos a nossa classe ExampleDiagnosticObserver
usando este pacote NuGet, obteremos o seguinte 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(); } }
Assim, agora podemos medir o tempo de execução de todas as consultas ao banco de dados de nosso aplicativo, praticamente sem alterar o código do próprio aplicativo.
Criando suas próprias instâncias DiagnosticListener
Ao usar o DiagnosticSource na prática, na maioria dos casos, você se inscreverá nos eventos existentes. Provavelmente, você não precisará criar suas próprias instâncias do DiagnosticListener
e enviar seus próprios eventos (apenas se você não estiver desenvolvendo nenhuma biblioteca); portanto, não vou me deter nesta seção por muito tempo.
Para criar sua própria instância do DiagnosticListener
será necessário declará-la como uma variável estática em algum lugar do código:
private static readonly DiagnosticSource _myDiagnosticSource = new DiagnosticListener("MyLibraty");
Depois disso, para enviar um evento, você pode usar um design do formulário:
if (_myDiagnosticSource.IsEnabled("MyEvent")) _myDiagnosticSource.Write("MyEvent", new { });
Para obter mais informações sobre como criar suas próprias instâncias do DiagnosticListener
, consulte o Guia do usuário do DiagnosticSource , que detalha as práticas recomendadas para usar o DiagnosticSource.
Conclusão
O exemplo que examinamos é certamente muito abstrato e dificilmente será útil em um projeto real. Mas mostra perfeitamente como esse mecanismo pode ser usado para monitorar e diagnosticar seus aplicativos.
No próximo artigo, darei uma lista de eventos conhecidos por mim que podem ser processados por meio do DiagnosticSource e mostrarei alguns exemplos práticos de seu uso.