자습서: .NET Core에서 EventCounters를 사용하여 성능 측정

이 문서의 적용 대상: ✔️ .NET Core 3.0 SDK 이상 버전

이 자습서에서는 이벤트 빈도가 높을 경우 성능을 측정하는 데 EventCounter를 사용하는 방법을 알아봅니다. 다양한 공식 .NET Core 패키지, 타사 공급자가 게시한 사용 가능한 카운터를 사용하거나 모니터링을 위한 자체 메트릭을 만들 수 있습니다.

이 자습서에서는 다음을 수행합니다.

필수 조건

이 자습서에서는 다음을 사용하여 작업을 수행합니다.

소스 가져오기

이 애플리케이션 예제는 모니터링의 기준으로 사용됩니다. 샘플 ASP.NET Core 리포지토리는 샘플 브라우저에서 사용할 수 있습니다. zip 파일을 다운로드하고, 다운로드가 끝나면 압축을 풀고, 즐겨 사용하는 IDE에서 엽니다. 애플리케이션을 빌드하고 실행하여 제대로 작동하는지 확인한 다음, 애플리케이션을 중지합니다.

EventSource 구현

밀리초 간격으로 발생하는 이벤트의 경우 이벤트당 오버헤드를 밀리초 미만으로 줄일 수 있습니다. 그러지 않으면 성능에 지대한 영향을 미칠 수 있습니다. 이벤트를 로깅하는 것은 디스크에 무언가를 쓰게 된다는 것을 의미합니다. 디스크가 충분하지 않으면 이벤트가 손실됩니다. 이벤트 자체를 기록하는 것 이외의 솔루션이 필요합니다.

많은 이벤트를 처리할 때 이벤트별 측정값을 파악하는 것은 유용하지 않습니다. 대부분의 경우에는 일부 통계만 있으면 됩니다. 따라서 프로세스 자체 내에서 통계를 가져온 다음, 경우에 따라 통계를 보고하는 이벤트를 작성할 수 있습니다. 이것이 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 명령과 비슷하지만 몇 가지 추가 매개 변수를 허용합니다. 원하는 출력 파일 이름과 형식을 지정할 수 있습니다. diagnostics.json이라는 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
    }
  ]
}

다음 단계