Tutorial: Medir o desempenho com EventCounters no .NET Core
Este artigo aplica-se a: ✔️ SDK .NET Core 3.0 e versões posteriores
Neste tutorial, irá aprender como um EventCounter pode ser utilizado para medir o desempenho com uma elevada frequência de eventos. Pode utilizar os contadores disponíveis publicados por vários pacotes .NET Core oficiais, fornecedores de terceiros ou criar as suas próprias métricas para monitorização.
Neste tutorial, vai:
- Implementar um EventSource.
- Monitorize contadores com contadores dotnet.
Pré-requisitos
O tutorial utiliza:
- SDK .NET Core 3.1 ou uma versão posterior.
- dotnet-counters para monitorizar contadores de eventos.
- Uma aplicação de destino de depuração de exemplo para diagnosticar.
Obter a origem
A aplicação de exemplo será utilizada como base para monitorização. O repositório de ASP.NET Core de exemplo está disponível no browser de exemplos. Transfira o ficheiro zip, extraia-o uma vez transferido e abra-o no seu IDE favorito. Crie e execute a aplicação para garantir que funciona corretamente e, em seguida, pare a aplicação.
Implementar um EventSource
Para eventos que ocorrem a cada poucos milissegundos, vai querer que a sobrecarga por evento seja baixa (menos de milissegundos). Caso contrário, o impacto no desempenho será significativo. Registar um evento significa que vai escrever algo no disco. Se o disco não for suficientemente rápido, perderá eventos. Precisa de uma solução que não o registo do evento propriamente dito.
Ao lidar com um grande número de eventos, saber a medida por evento também não é útil. Na maioria das vezes, só precisa de algumas estatísticas. Assim, pode obter as estatísticas dentro do próprio processo e, em seguida, escrever um evento de vez em quando para comunicar as estatísticas, é isso que EventCounter vai fazer.
Segue-se um exemplo de como implementar um System.Diagnostics.Tracing.EventSource. Crie um novo ficheiro com o nome MinimalEventCounterSource.cs e utilize o fragmento de código como origem:
using System.Diagnostics.Tracing;
[EventSource(Name = "Sample.EventCounter.Minimal")]
public sealed class MinimalEventCounterSource : EventSource
{
public static readonly MinimalEventCounterSource Log = new MinimalEventCounterSource();
private EventCounter _requestCounter;
private MinimalEventCounterSource() =>
_requestCounter = new EventCounter("request-time", this)
{
DisplayName = "Request Processing Time",
DisplayUnits = "ms"
};
public void Request(string url, long elapsedMilliseconds)
{
WriteEvent(1, url, elapsedMilliseconds);
_requestCounter?.WriteMetric(elapsedMilliseconds);
}
protected override void Dispose(bool disposing)
{
_requestCounter?.Dispose();
_requestCounter = null;
base.Dispose(disposing);
}
}
A EventSource.WriteEvent linha é a EventSource parte e não faz parte de , foi escrita para mostrar que pode registar uma mensagem juntamente com o contador de EventCountereventos.
Adicionar um filtro de ação
O código fonte de exemplo é um projeto ASP.NET Core. Pode adicionar um filtro de ação globalmente que irá registar o tempo total do pedido. Crie um novo ficheiro com o nome LogRequestTimeFilterAttribute.cs e utilize o seguinte código:
using System.Diagnostics;
using Microsoft.AspNetCore.Http.Extensions;
using Microsoft.AspNetCore.Mvc.Filters;
namespace DiagnosticScenarios
{
public class LogRequestTimeFilterAttribute : ActionFilterAttribute
{
readonly Stopwatch _stopwatch = new Stopwatch();
public override void OnActionExecuting(ActionExecutingContext context) => _stopwatch.Start();
public override void OnActionExecuted(ActionExecutedContext context)
{
_stopwatch.Stop();
MinimalEventCounterSource.Log.Request(
context.HttpContext.Request.GetDisplayUrl(), _stopwatch.ElapsedMilliseconds);
}
}
}
O filtro de ação inicia um Stopwatch à medida que o pedido começa e para depois de ser concluído, capturando o tempo decorrido. Os milissegundos totais são registados na MinimalEventCounterSource instância singleton. Para que este filtro seja aplicado, tem de o adicionar à coleção de filtros. No ficheiro Startup.cs , atualize o ConfigureServices método em incluir este filtro.
public void ConfigureServices(IServiceCollection services) =>
services.AddControllers(options => options.Filters.Add<LogRequestTimeFilterAttribute>())
.AddNewtonsoftJson();
Monitorizar contador de eventos
Com a implementação num EventSource filtro de ação personalizado e , crie e inicie a aplicação. Iniciou a métrica no EventCounter, mas, a menos que aceda às estatísticas da mesma, não é útil. Para obter as estatísticas, tem de ativar o EventCounter ao criar um temporizador que seja acionado com a frequência que quiser, bem como um serviço de escuta para capturar os eventos. Para tal, pode utilizar contadores dotnet.
Utilize o comando ps dotnet-counters para apresentar uma lista de processos .NET que podem ser monitorizados.
dotnet-counters ps
Com o identificador do processo a partir da saída do dotnet-counters ps comando, pode começar a monitorizar o contador de eventos com o seguinte dotnet-counters monitor comando:
dotnet-counters monitor --process-id 2196 --counters Sample.EventCounter.Minimal,Microsoft.AspNetCore.Hosting[total-requests,requests-per-second],System.Runtime[cpu-usage]
Enquanto o dotnet-counters monitor comando está em execução, mantenha a tecla F5 no browser para iniciar a emissão de pedidos contínuos para o https://localhost:5001/api/values ponto final. Após alguns segundos, prima q para parar
Press p to pause, r to resume, q to quit.
Status: Running
[Microsoft.AspNetCore.Hosting]
Request Rate / 1 sec 9
Total Requests 134
[System.Runtime]
CPU Usage (%) 13
[Sample.EventCounter.Minimal]
Request Processing Time (ms) 34.5
O dotnet-counters monitor comando é ótimo para monitorização ativa. No entanto, poderá querer recolher estas métricas de diagnóstico para pós-processamento e análise. Para tal, utilize o dotnet-counters collect comando . O collect comando switch é semelhante ao monitor comando, mas aceita alguns parâmetros adicionais. Pode especificar o nome e o formato de ficheiro de saída pretendidos. Para um ficheiro JSON com o nome diagnostics.json , utilize o seguinte comando:
dotnet-counters collect --process-id 2196 --format json -o diagnostics.json --counters Sample.EventCounter.Minimal,Microsoft.AspNetCore.Hosting[total-requests,requests-per-second],System.Runtime[cpu-usage]
Novamente, enquanto o comando está em execução, mantenha f5 no browser para começar a emitir pedidos contínuos para o https://localhost:5001/api/values ponto final. Após alguns segundos, prima q para parar. O ficheiro diagnostics.json foi escrito. No entanto, o ficheiro JSON escrito não tem avanço; para legibilidade, é avanço aqui.
{
"TargetProcess": "DiagnosticScenarios",
"StartTime": "8/5/2020 3:02:45 PM",
"Events": [
{
"timestamp": "2020-08-05 15:02:47Z",
"provider": "System.Runtime",
"name": "CPU Usage (%)",
"counterType": "Metric",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:47Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Request Rate / 1 sec",
"counterType": "Rate",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:47Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Total Requests",
"counterType": "Metric",
"value": 134
},
{
"timestamp": "2020-08-05 15:02:47Z",
"provider": "Sample.EventCounter.Minimal",
"name": "Request Processing Time (ms)",
"counterType": "Metric",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:47Z",
"provider": "System.Runtime",
"name": "CPU Usage (%)",
"counterType": "Metric",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:48Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Request Rate / 1 sec",
"counterType": "Rate",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:48Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Total Requests",
"counterType": "Metric",
"value": 134
},
{
"timestamp": "2020-08-05 15:02:48Z",
"provider": "Sample.EventCounter.Minimal",
"name": "Request Processing Time (ms)",
"counterType": "Metric",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:48Z",
"provider": "System.Runtime",
"name": "CPU Usage (%)",
"counterType": "Metric",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:50Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Request Rate / 1 sec",
"counterType": "Rate",
"value": 0
},
{
"timestamp": "2020-08-05 15:02:50Z",
"provider": "Microsoft.AspNetCore.Hosting",
"name": "Total Requests",
"counterType": "Metric",
"value": 134
},
{
"timestamp": "2020-08-05 15:02:50Z",
"provider": "Sample.EventCounter.Minimal",
"name": "Request Processing Time (ms)",
"counterType": "Metric",
"value": 0
}
]
}
