Tutorial: medir o desempenho usando EventCounters no .NET Core
Este artigo se aplica a: ✔️ SDK do .NET Core 3.0 e versões posteriores
Neste tutorial, você aprenderá como um EventCounter pode ser usado para medir o desempenho com uma alta frequência de eventos. Você pode usar os contadores disponíveis publicados por vários pacotes oficiais do .NET Core, provedores de terceiros ou criar suas próprias métricas de monitoramento.
Neste tutorial, você irá:
- Implemente um EventSource.
- Monitore contadores com dotnet-counters.
Pré-requisitos
O tutorial usa:
- O SDK do .NET Core 3.1 ou uma versão posterior.
- dotnet-counters para monitorar contadores de eventos.
- Um aplicativo de destino de depuração de exemplo a ser diagnosticado.
Obter a origem
O aplicativo de exemplo será usado como base para monitoramento. O repositório de ASP.NET Core de exemplo está disponível no navegador de exemplos. Baixe o arquivo zip, extraia e abra no seu IDE favorito. Crie e execute o aplicativo para garantir que ele funcione corretamente e, em seguida, interrompa o aplicativo.
Implementar um EventSource
Para eventos que acontecem a cada poucos milissegundos, é recomendável que a sobrecarga por evento seja baixa (inferior a um milissegundo). Caso contrário, o impacto sobre o desempenho será significativo. Registrar em log um evento significa que você escreverá algo no disco. Se o disco não for rápido o suficiente, você perderá eventos. Você precisa de uma solução diferente do mero registro de eventos.
Ao lidar com um grande número de eventos, saber a medida por evento também não será útil. Na maioria das vezes, tudo o que você precisa é de apenas alguns cálculos estatísticos. Assim, você pode obter as estatísticas dentro do próprio processo e, em seguida, gravar um evento de vez em quando para alimentar essas estatísticas; isso é o que EventCounter fará.
Veja abaixo um exemplo de como implementar um System.Diagnostics.Tracing.EventSource. Crie um arquivo chamado MinimalEventCounterSource.cs e use o snippet de código como a origem dele:
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 linha EventSource.WriteEvent é a parte EventSource e não faz parte de EventCounter, ela foi gravada para mostrar que você pode registrar uma mensagem juntamente com o contador de eventos.
Adicionar um filtro de ação
O código-fonte de exemplo é um projeto do ASP.NET Core. Você pode adicionar um filtro de ação globalmente, que vai registrar o tempo total da solicitação. Crie um arquivo chamado LogRequestTimeFilterAttribute.cs e use 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 quando a solicitação começa e interrompe quando ela termina, capturando o tempo decorrido. O total de milissegundos é registrado na instância singleton de MinimalEventCounterSource. Para que esse filtro seja aplicado, você precisa adicioná-lo à coleção de filtros. No arquivo Startup.cs, atualize o método ConfigureServices para incluir esse filtro.
public void ConfigureServices(IServiceCollection services) =>
services.AddControllers(options => options.Filters.Add<LogRequestTimeFilterAttribute>())
.AddNewtonsoftJson();
Monitorar o contador de eventos
Com a implementação em um EventSource e o filtro de ação personalizado, compile e inicie o aplicativo. Você registrou a métrica em EventCounter, mas, a menos que acesse as estatísticas dela, ela não será útil. Para obter as estatísticas, você precisa habilitar EventCounter criando um temporizador que seja acionado com a mesma frequência que os eventos, bem como um ouvinte para capturar os eventos. Para fazer isso, você pode usar dotnet-counters.
Use o comando dotnet-counters ps para exibir uma lista de processos .NET que podem ser monitorados.
dotnet-counters ps
Usando o identificador de processo da saída do comando dotnet-counters ps, você pode começar a monitorar o contador de eventos com o seguinte comando dotnet-counters monitor:
dotnet-counters monitor --process-id 2196 --counters Sample.EventCounter.Minimal,Microsoft.AspNetCore.Hosting[total-requests,requests-per-second],System.Runtime[cpu-usage]
Enquanto o comando dotnet-counters monitor estiver em execução, mantenha pressionado F5 no navegador para iniciar a emissão de solicitações contínuas ao ponto de extremidade https://localhost:5001/api/values. Após alguns segundos, interrompa pressionando q
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 comando dotnet-counters monitor é ótimo para monitoramento ativo. No entanto, talvez você queira coletar essas métricas de diagnóstico para pós-processamento e análise. Para isso, use o comando dotnet-counters collect. O comando da opção collect é semelhante ao comando monitor, mas aceita alguns parâmetros adicionais. Você pode especificar o nome e o formato desejados para o arquivo de saída. Para um arquivo JSON chamado diagnostics.json, use 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 estiver em execução, mantenha pressionado F5 no navegador para iniciar a emissão de solicitações contínuas ao ponto de extremidade https://localhost:5001/api/values. Depois de alguns segundos, pare pressionando q. O arquivo diagnostics.json é gravado. No entanto, o arquivo JSON gravado não está recuado; para legibilidade, ele é recuado 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
}
]
}
