.NET 任务的性能指标/诊断

Question

有没有办法从 .NET 中获取关于（C# 5 或更高版本，因此是异步/等待后）待执行任务的数量以及类似指标的数据，用于诊断生产服务器发生的问题？

我正在讨论的案例是一个 async-all-the-way-down 系统（例如，一个大型并行套接字服务器，其中每个请求从一开始就异步运行），其中初始任务生成多个任务，每个任务都需要处理时间（或每个启动更多任务），或生成任务，其中一些阻塞（如第三方代码）和一些正常工作的异步。我见过两种情况很难有效诊断：

• 在正常负载下，一切正常，但如果有足够的请求，CPU 会很快跃升至 100%，所有请求完成的速度越来越慢。当负载减少时，CPU 将保持在 100%，直到大部分待处理任务逐渐完成，然后 CPU 降至正常水平。
• 在正常负载下，一切正常，但如果有足够多的请求，则某些请求（所有这些都是正确异步的）根本无法完成或非常缓慢。当负载减轻时，CPU 将保持在 100%，同时它们都被处理，但任务完成率会出现减速带，并在短时间内显着减慢。

我已经尝试为此编写一个简单的测试，但是没有明显的方法来限制执行程序的数量以及我需要创建的测试它的任务数量，这使得解析信息变得非常困难。通过尝试注销调试信息来不干扰测试本身也非常困难。我将继续尝试创建更好的测试用例并在需要时修改我的问题。

根据我对问题和异步任务系统的理解，这两者实际上都是对实际运行任务的执行程序的争用。

发生第一种情况是因为正在创建的任务多于实际完成的任务，在这种情况下，即使在负载高到足以锁定服务之前，挂起任务的计数器也有助于诊断此问题。

第二种情况的发生是因为一组任务运行时间足够长，但随着时间的推移（有足够的负载）所有执行程序最终同时运行这些任务。一旦完成，它就会处理一些任务，很快就会被另一个长期运行的任务取代。在这种情况下，待处理任务计数器以及其他一些指标会很有用。

是否有任何可用的东西，或者是否有一些未记录/hacky 的方法可以将一些代码移植到应用程序中启动的每个任务的开始/结束，以使其注销/测量这些东西并在何时发出警告任务号爆炸了？

Answer 1

似乎 Leonid Vasilyev 的回答对你来说已经足够了，但我想分享一下我的经验，当涉及到任务失败或有时比平时花费更长的时间。

这里最大的罪魁祸首是 ****Context Switching**** ，您启动的任务越多，CPU 就必须跟踪上下文。相信我，一个 CPU 执行 100 个繁重的任务比执行 100 个轻量级任务的效率更高。

对我来说，诀窍是根据提交的请求分析负载模式（我们使用消息队列）并根据模式保持最佳状态。我还在每个任务结束时手动进行 ForceGC 收集。

我知道您正在寻找有助于分析的工具，我认为这会有所帮助。我认为对于这类问题，最好先关注传入流量，而不是分析我们如何处理这些流量。

Answer 2

据我了解，如果我们可以在调用任何 await 之前使用方法名称、数据时间和 sessionID 添加某种类型的日志记录（首选 DBlogging）。在等待语句之后清除记录，等待完成后删除记录（插入/更新记录等待时间）。因此，可以实时分析等待方法的会话数。我希望这行得通。我曾尝试只使用 txt 文件创建和删除，并且成功了。

Answer 3

最简单的方法是创建Task.Run、Task.Start 等的替代方案，1) 调用真正的运行/启动和 2) 在ConcurrentDictionary 中记录信息（例如任务本身，线程等）

实际上，您正在编写一个专门的分析器：

public static class TaskExtensions
{
    Task Run(
        Action action,
        [CallerMemberName] string caller = null,
        [CallerFilePath] string callerFile = null,
        [CallerLineNumber] int lineNumber = 0)
    {
        tasks.Add(new Entry { ... });
        return Task.Run(action);
    }

    // etc.
}

class Entry
{
    Task Task { get; set; }
    string CallerMemberName { get; set; }
    string CallerFilePath { get; set; }
    string CallerFileNumber { get; set; }
    int ThreadId { get; set; }
    DateTime Started { get; set; }
    DateTime Stopped { get; set; }
}

var tasks = new ConcurrentDictionary<string, Entry>();

我们使用来电者信息给我们一个唯一的密钥，因为task IDs 不能保证是唯一的。

在另一个线程或任务中，遍历所有任务，检查它们的状态（IsCompleted、IsFaulted、IsCanceled）并记录诸如它们运行了多长时间等指标。

您可能希望在民意调查之间有短暂的延迟，因此这会限制您在指标精度方面的延迟持续时间。因为民意调查是在他们自己的任务中运行的，所以您的主线代码应该不会受到太大影响，并且您应该能够了解正在发生的事情。

顺便说一句，既然您提到了套接字，您可能会面临套接字进入TIME_WAIT 的情况。发生这种情况时，您可能会遇到您所说的减速。我以前见过这种情况，这肯定是在负载下发生的。

为满足不将指标记录投入生产的需要，请在您的较低（测试）环境中围绕指标代码使用编译器指令，并使用该指令为这些环境创建构建配置。

Answer 4

您可以从EventListener 继承一个类来处理Task Parallel Library 产生的事件。或许，您可以通过这种方式计算排队和正在运行的任务，并将与任务关联的分析信息存储在ConcurrentDictionary 中。但是，存在一些复杂情况，例如任务 ID 的不唯一性或此分析的性能影响。

示例实现：

public class TplEventListener : EventListener
{
    static readonly Guid _tplSourceGuid = new Guid("2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5");
    readonly EventLevel _handledEventsLevel;

    public TplEventListener(EventLevel handledEventsLevel)
    {
        _handledEventsLevel = handledEventsLevel;
    }

    protected override void OnEventSourceCreated(EventSource eventSource)
    {
        if (eventSource.Guid == _tplSourceGuid)
            EnableEvents(eventSource, _handledEventsLevel);
    }

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        if (eventData.EventSource.Guid != _tplSourceGuid)
            return;

        switch (eventData.EventId)
        {
            // TODO: Add case for each relevant EventId (such as TASKSCHEDULED_ID and TASKWAITBEGIN_ID)
            // and explore relevant data (such as task Id) in eventData.Payload. Payload is described by 
            // eventData.PayloadNames.
            // For event ids and payload meaning explore TplEtwProvider source code 
            // (https://referencesource.microsoft.com/#mscorlib/system/threading/Tasks/TPLETWProvider.cs,183).
            default:
                var message = new StringBuilder();
                message.Append(eventData.EventName);
                message.Append("(");
                message.Append(eventData.EventId);
                message.Append(") { ");
                if (!string.IsNullOrEmpty(eventData.Message))
                {
                    message.Append("Message = \"");
                    message.AppendFormat(eventData.Message, eventData.Payload.ToArray());
                    message.Append("\", ");
                }
                for (var i = 0; i < eventData.Payload.Count; ++i)
                {
                    message.Append(eventData.PayloadNames[i]);
                    message.Append(" = ");
                    message.Append(eventData.Payload[i]);
                    message.Append(", ");
                }
                message[message.Length - 2] = ' ';
                message[message.Length - 1] = '}';
                Console.WriteLine(message);
                break;
        }
    }
}

在每个 AppDomain 中初始化并存储 new TplEventListener(EventLevel.LogAlways)，您将获得类似于以下内容的日志：

NewID(26) { TaskID = 1 }
TaskScheduled(7) { Message = "任务 1 计划到 TaskScheduler 1。", OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, TaskID = 1, CreatingTaskID = 0, TaskCreationOptions = 8192 }
NewID(26) { 任务 ID = 2 }
TraceOperationBegin(14) { TaskID = 2, OperationName = Task.ContinueWith: b__0, RelatedContext = 0 }
TaskStarted(8) { Message = "正在执行的任务 1。", OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, TaskID = 1 }
AwaitTaskContinuationScheduled(12) { OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, ContinuwWithTaskId = 2 }
NewID(26) { 任务 ID = 3 }
TraceOperationBegin(14) { TaskID = 3, OperationName = Async: d__3, RelatedContext = 0 }
NewID(26) { 任务 ID = 4 }
TaskWaitBegin(10) { Message = "在任务 4 上开始等待 (2)。", OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, TaskID = 4, Behavior = 2, ContinueWithTaskID = 3 }
TaskWaitBegin(10) { Message = "在任务 3 上开始等待 (1)。", OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, TaskID = 3, Behavior = 1, ContinueWithTaskID = 0 }
TraceSynchronousWorkBegin(17) { TaskID = 1, Work = 2 }
TraceSynchronousWorkEnd(18) { 工作 = 2 }
TraceOperationEnd(15) { 任务 ID = 1，状态 = 1 }
RunningContinuation(20) { TaskID = 1, Object = 0 }
TaskCompleted(9) { Message = "Task 1 completed.", OriginatingTaskSchedulerID = 1, OriginatingTaskID = 0, TaskID = 1, IsExceptional = False }

更多信息请查看：

• Async Causality Chain Tracking Andrew Stasyuk 的文章
• A Few Words on Task.Id (and TaskScheduler.Id) Stephen Cleary 的文章。
• How do I listen to TPL TaskStarted/TaskCompleted ETW events StackOverflow 上的讨论
• System.Threading.Tasks.TplEtwProvider源代码

Answer 5

在生产环境中Metrics.NET 库很方便。您可以检测代码并定期将收集的数据写入本地文件或数据库。在开发环境中，您可以使用 Visual Studio 分析器来探索 CPU 和地址空间的使用情况。请参阅 .NET Memory Allocation Profiling with Visual Studio 2012 Stephen Toub 的文章。

来自 Metrics.NET wiki 的相关摘录：

Metrics.NET 库提供了五种可以记录的指标：

• Meters记录事件发生的频率
• Histograms 测量数据流中值的分布
• Timers 保留某类事件持续时间的直方图及其发生率的计量表
• Counters 可以递增或递减的 64 位整数
• Gauges 瞬时值

和仪表示例：

public class SampleMetrics
{
    private readonly Timer timer = Metric.Timer("Requests", Unit.Requests);
    private readonly Counter counter = Metric.Counter("ConcurrentRequests", Unit.Requests);

    public void Request(int i)
    {
        this.counter.Increment();
        using (this.timer.NewContext()) // measure until disposed
        {
            // do some work
        }
        this.counter.Decrement();
    }
}

更多信息请查看：

• Async Performance: Understanding the Costs of Async and AwaitStephen Toub 的文章
• async/await for high performance server applications? StackOverflow 上的讨论
• Metrics, Metrics, Everywhere Coda Hale 的视频