Учебник. Измерение производительности с помощью EventCounters в .NET Core

Статья
06/23/2023

Эта статья относится к: ✔️ пакету SDK для .NET Core 3.0 и более поздних версий

В этом руководстве вы узнаете, как можно использовать EventCounter для измерения производительности с высокой частотой событий. Вы можете использовать доступные счетчики, опубликованные в разных официальных пакетах .NET Core или сторонними поставщиками, либо создать собственные метрики для мониторинга.

Изучив данный учебник, вы научитесь:

Реализовывать EventSource.
Организовывать мониторинг счетчиков с помощью dotnet-counters.

Предварительные требования

В этом учебнике используется:

Пакет SDK для .NET Core 3.1 или более поздней версии.
dotnet-counters для мониторинга счетчиков событий.
Пример целевого приложения отладки для диагностики.

Получение исходного кода

Пример приложения будет использоваться в качестве основания для мониторинга. Пример репозитория ASP.NET доступен в обозревателе примеров. Скачайте ZIP-файл, извлеките его содержимое и откройте его в избранной интегрированной среде разработки. Выполните сборку приложения и запустите его, чтобы убедиться, что оно работает правильно, а затем закройте приложение.

Реализация счетчика событий

Для событий, происходящих каждые несколько миллисекунд, необходимо, чтобы затраты на событие были низкими (меньше миллисекунд). В противном случае влияние на производительность будет значительным. Регистрация события означает, что вы собираетесь записать что-то на диск. Если диск недостаточно быстродействующий, события будут потеряны. Потребуется решение, отличное от регистрации самого события.

При работе с большим количеством событий знание меры для каждого события не имеет смысла. В большинстве случаев достаточно лишь некоторой статистики. Так что вы можете получить статистику внутри самого процесса, а затем написать событие один раз в течение определенного времени для передачи статистики. Именно это и делает EventCounter.

Ниже приведен пример реализации System.Diagnostics.Tracing.EventSource. Создайте новый файл с именем MinimalEventCounterSource.cs и используйте фрагмент кода в качестве источника:

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

Строка EventSource.WriteEvent — это EventSource часть, которая не является частью EventCounter. Она была написана для того, чтобы показать, что можно зарегистрировать сообщение вместе со счетчиком событий.

Добавление фильтра действий

Пример исходного кода является проектом ASP.NET Core. Вы можете глобально добавить фильтр действий, который будет регистрировать общее время запроса. Создайте новый файл с именем LogRequestTimeFilterAttribute.cs и используйте следующий код:

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

Фильтр действий запускает , Stopwatch когда начинается запрос, и останавливается после его завершения, записывая затраченное время. Общее количество миллисекундах регистрируется в одноэлементном экземпляре MinimalEventCounterSource . Чтобы применить этот фильтр, необходимо добавить его в коллекцию фильтров. В файле Startup.cs обновите метод ConfigureServices, чтобы включить этот фильтр.

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

Мониторинг счетчика событий

Реализовав EventSource и настраиваемый фильтр действий, создайте и запустите приложение. Вы зарегистрировали метрику в EventCounter, но пока вы не получите доступ к статистике из нее, пользы от нее никакой. Чтобы получить статистику, необходимо включить EventCounter, создав таймер, который срабатывает с периодичностью, которая требуется для событий и нужна прослушивателю для записи событий. Для этого можно использовать dotnet-counters.

Используйте команду dotnet-counters ps, чтобы отобразить список процессов .NET, которые можно отслеживать.

dotnet-counters ps

Используя идентификатор процесса из выходных данных команды dotnet-counters ps, можно начать мониторинг счетчика событий с помощью следующей команды 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]

Во время выполнения команды dotnet-counters monitor удерживайте нажатой клавишу F5 в браузере, чтобы начать выдачу непрерывных запросов к конечной точке https://localhost:5001/api/values. Через несколько секунд нажмите клавишу 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

Команда dotnet-counters monitor отлично подходит для активного мониторинга. Однако может потребоваться собрать эти метрики диагностики для обработки и анализа. Для этого используйте команду dotnet-counters collect. Команда collect аналогична команде monitor, но принимает несколько дополнительных параметров. Можно указать требуемое имя выходного файла и формат. Для файла JSON с именем diagnostics.json используйте следующую команду:

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]

Во время выполнения команды удерживайте нажатой клавишу F5 в браузере, чтобы начать выдачу непрерывных запросов к конечной точке https://localhost:5001/api/values. Через несколько секунд нажмите клавишу q. Файл diagnostics.json будет записан. Однако файл JSON не имеет отступа; для удобства чтения здесь он отображается с отступом.

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

Дальнейшие действия

Счетчики событий