教程:使用 .NET Core 中的 EventCounters 衡量性能Tutorial: Measure performance using EventCounters in .NET Core

本文适用于: ✔️ .NET Core 3.0 SDK 及更高版本This article applies to: ✔️ .NET Core 3.0 SDK and later versions

本教程将介绍如何使用 EventCounter 衡量高频率事件的性能。In this tutorial, you'll learn how an EventCounter can be used to measure performance with a high frequency of events. 可以使用由各种官方 .NET Core 包或第三方提供者发布的可用的计数器,或创建自己的监视指标。You can use the available counters published by various official .NET Core packages, third-party providers, or create your own metrics for monitoring.

在本教程中,将:In this tutorial, you will:

先决条件Prerequisites

本教程使用:The tutorial uses:

获取源Get the source

示例应用程序将用作监视的基础。The sample application will be used as a basis for monitoring. 示例浏览器中提供了示例 ASP.NET Core 存储库The sample ASP.NET Core repository is available from the samples browser. 下载 zip 文件,下载后提取它,并在你喜欢的 IDE 中打开它。You download the zip file, extract it once downloaded, and open it in your favorite IDE. 生成并运行应用程序以确保它正常工作,然后停止应用程序。Build and run the application to ensure that it works properly, then stop the application.

实现 EventSourceImplement an EventSource

对于每隔几毫秒发生的事件,最好使每个事件的开销较低(小于一毫秒)。For events that happen every few milliseconds, you'll want the overhead per event to be low (less than a millisecond). 否则,对性能的影响将很大。Otherwise, the impact on performance will be significant. 记录事件意味着你将向磁盘写入内容。Logging an event means you're going to write something to disk. 如果磁盘不够快,你将丢失事件。If the disk is not fast enough, you will lose events. 你需要一个解决方案,而不是记录事件本身。You need a solution other than logging the event itself.

在处理大量事件时,了解每个事件的度量值也无济于事。When dealing with a large number of events, knowing the measure per event is not useful either. 大多数时候,你只需要一些统计信息。Most of the time all you need is just some statistics out of it. 因此,你可以在进程本身中获取统计信息,然后偶尔编写一个事件来报告统计信息,这是 EventCounter 将执行的操作。So you could get the statistics within the process itself and then write an event once in a while to report the statistics, that's what EventCounter will do.

下面是有关如何实现 System.Diagnostics.Tracing.EventSource 的示例。Below is an example of how to implement an System.Diagnostics.Tracing.EventSource. 创建名为 MinimalEventCounterSource.cs 的新文件,并使用代码片段作为其源:Create a new file named MinimalEventCounterSource.cs and use the code snippet as its source:

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, float 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 的一部分,编写它是为了表明你可以一起记录消息和事件计数器。The EventSource.WriteEvent line is the EventSource part and is not part of EventCounter, it was written to show that you can log a message together with the event counter.

添加操作筛选器Add an action filter

示例源代码是 ASP.NET Core 项目。The sample source code is an ASP.NET Core project. 可以全局添加将记录总请求时间的操作筛选器You can add an action filter globally that will log the total request time. 创建名为 LogRequestTimeFilterAttribute.cs 的新文件,并使用以下代码:Create a new file named LogRequestTimeFilterAttribute.cs, and use the following code:

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,并在其完成后停止,捕获运行时间。The action filter starts a Stopwatch as the request begins, and stops after it has completed, capturing the elapsed time. 总毫秒数记录到 MinimalEventCounterSource 单一实例。The total milliseconds is logged to the MinimalEventCounterSource singleton instance. 为了应用此筛选器,需要将其添加到筛选器集合。In order for this filter to be applied, you need to add it to the filters collection. 在 Startup.cs 文件中,更新包含此筛选器的 ConfigureServices 方法。In the Startup.cs file, update the ConfigureServices method in include this filter.

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

监视事件计数器Monitor event counter

通过 EventSource 上的实现和自定义操作筛选器,生成和启动应用程序。With the implementation on an EventSource and the custom action filter, build and launch the application. 你已将指标记录到 EventCounter 中,但除非你从其中访问统计信息,否则它将不起作用。You logged the metric to the EventCounter, but unless you access the statistics from of it, it is not useful. 要获取统计信息,需要通过创建以所需事件频率触发的计时器来启用 EventCounter,并启用侦听器来捕获事件。To get the statistics, you need to enable the EventCounter by creating a timer that fires as frequently as you want the events, as well as a listener to capture the events. 为此,可以使用 dotnet-countersTo do that, you can use dotnet-counters.

使用 dotnet-counters ps 命令来显示可监视的 .NET 进程的列表。Use the dotnet-counters ps command to display a list of .NET processes that can be monitored.

dotnet-counters ps

通过使用 dotnet-counters ps 命令的输出中的进程标识符,你可以使用以下 dotnet-counters monitor 命令开始监视事件计数器:Using the process identifier from the output of the dotnet-counters ps command, you can start monitoring the event counter with the following dotnet-counters monitor command:

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 终结点发出连续请求。While the dotnet-counters monitor command is running, hold F5 on the browser to start issuing continuous requests to the https://localhost:5001/api/values endpoint. 几秒后按 q 以停止After a few seconds stop by pressing 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 命令非常适合主动监视。The dotnet-counters monitor command is great for active monitoring. 不过,可以收集这些诊断指标以便进行后续处理和分析。However, you may want to collect these diagnostic metrics for post processing and analysis. 为此,请使用 dotnet-counters collect 命令。For that, use the dotnet-counters collect command. collect 开关命令类似于 monitor 命令,但接受几个其他参数。The collect switch command is similar to the monitor command, but accepts a few additional parameters. 你可以指定所需的输出文件名和格式。You can specify the desired output file name and format. 对于名为 diagnostics.json 的 JSON 文件,请使用以下命令:For a JSON file named diagnostics.json use the following command:

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 终结点发出连续请求。Again, while the command is running, hold F5 on the browser to start issuing continuous requests to the https://localhost:5001/api/values endpoint. 几秒后按 q 以停止。After a few seconds stop by pressing q. 写入 diagnostics.json 文件。The diagnostics.json file is written. 写入的 JSON 文件不会缩进;但为了提升可读性,在这里进行了缩进。The JSON file that is written is not indented, however; for readability it is indented here.

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

后续步骤Next steps