Esercitazione: Misurare le prestazioni usando EventCounters in .NET Core

  • Articolo

Questo articolo si applica a: ✔️ .NET Core 3.0 SDK e versioni successive

In questa esercitazione si apprenderà come usare un EventCounter per misurare le prestazioni con una frequenza elevata di eventi. È possibile usare i contatori disponibili pubblicati da vari pacchetti .NET Core ufficiali, provider di terze parti o creare metriche personalizzate per il monitoraggio.

Questa esercitazione illustra come:

Prerequisiti

L'esercitazione usa:

Ottenere l'origine

L'applicazione di esempio verrà usata come base per il monitoraggio. È disponibile il repository ASP.NET Core di esempio nel browser degli esempi. Scaricare il file ZIP, estrarlo dopo averlo scaricato e aprirlo nell'IDE preferito. Compilare ed eseguire l'applicazione per assicurarsi che funzioni correttamente, quindi arrestare l'applicazione.

Implementare EventSource

Per gli eventi che si verificano ogni pochi millisecondi, è preferibile che l'overhead per evento sia basso (inferiore a un millisecondo). In caso contrario, l'impatto sulle prestazioni sarà significativo. Registrare un evento significa scrivere qualcosa su disco. Se il disco non è abbastanza veloce, andranno persi degli eventi. È necessaria una soluzione diversa dalla registrazione dell'evento stesso.

Quando si deve gestire un numero elevato di eventi, anche conoscere la misura per evento non è utile. Nella maggior parte dei casi serve semplicemente recuperare alcune statistiche. Si potrebbero quindi ottenere le statistiche all'interno del processo stesso e quindi scrivere un evento ogni tanto per comunicare le statistiche. Questo è quello che farà EventCounter.

Di seguito è riportato un esempio di come implementare System.Diagnostics.Tracing.EventSource. Creare un nuovo file denominato MinimalEventCounterSource.cs e usare il frammento di codice come origine:

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);
    }
}

La riga EventSource.WriteEvent è la parte EventSource e non fa parte di EventCounter. È stata scritta per mostrare che è possibile registrare un messaggio insieme al contatore eventi.

Aggiungere un filtro azioni

Il codice sorgente di esempio è un progetto ASP.NET Core. È possibile aggiungere un filtro azioni a livello globale per registrare il tempo totale della richiesta. Creare un nuovo file denominato LogRequestTimeFilterAttribute.cs e usare il codice seguente:

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);
        }
    }
}

Il filtro azioni avvia uno Stopwatch quando inizia la richiesta e si arresta dopo il completamento, acquisendo il tempo trascorso. I millisecondi totali vengono registrati nell'istanza singleton di MinimalEventCounterSource. Per applicare questo filtro, è necessario aggiungerlo alla raccolta di filtri. Nel file Startup.cs aggiornare il metodo ConfigureServices per includere questo filtro.

public void ConfigureServices(IServiceCollection services) =>
    services.AddControllers(options => options.Filters.Add<LogRequestTimeFilterAttribute>())
            .AddNewtonsoftJson();

Monitorare il contatore eventi

Con l'implementazione in EventSource e il filtro azioni personalizzato, compilare e avviare l'applicazione. La metrica è stata registrata in EventCounter, ma a meno che non si acceda alle statistiche dal contatore, non è utile. Per ottenere le statistiche, è necessario abilitare EventCounter tramite la creazione di un timer che viene attivato con la frequenza con cui si vogliono recuperare gli eventi, nonché un listener per acquisire gli eventi. A tale scopo, è possibile usare dotnet-counters.

Usare il comando dotnet-counters ps per visualizzare un elenco di processi .NET che possono essere monitorati.

dotnet-counters ps

Usando l'identificatore del processo dell'output del comando dotnet-counters ps, è possibile avviare il monitoraggio del contatore eventi con il comando dotnet-counters monitor seguente:

dotnet-counters monitor --process-id 2196 --counters Sample.EventCounter.Minimal,Microsoft.AspNetCore.Hosting[total-requests,requests-per-second],System.Runtime[cpu-usage]

Mentre il comando dotnet-counters monitor è in esecuzione, tenere premuto F5 nel browser per avviare l'invio di richieste continue all'endpoint https://localhost:5001/api/values. Dopo pochi secondi arrestare l'operazione premendo 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

Il comando dotnet-counters monitor è molto utile per il monitoraggio attivo. Tuttavia, potrebbe essere necessario raccogliere queste metriche di diagnostica per la post-elaborazione e l'analisi. A tale scopo, usare il comando dotnet-counters collect. Il comando switch collect è simile al comando monitor, ma accetta alcuni parametri aggiuntivi. È possibile specificare il nome e il formato del file di output desiderati. Per un file JSON denominato diagnostics.json usare il comando seguente:

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]

Ancora una volta, mentre il comando è in esecuzione, tenere premuto F5 nel browser per avviare l'invio di richieste continue all'endpoint https://localhost:5001/api/values. Dopo pochi secondi arrestare l'operazione premendo q. Verrà scritto il file diagnostics.json. Il file JSON scritto non è tuttavia rientrato; come lo è in questo articolo per una migliore leggibilità.

{
  "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
    }
  ]
}

Passaggi successivi

EventCounters