线程等待时间

Question

我确实尝试使用 TraceProcessing 从上下文切换事件中重现线程等待时间。最简单的方法是将所有进程的所有线程的等待时间相加。通常我想要一个特定的线程，但这里只显示问题是最简单的代码：

using ITraceProcessor processor = TraceProcessor.Create(myEtlFile, new TraceProcessorSettings
{
  AllowLostEvents = true,
});

IPendingResult<IContextSwitchDataSource> myContextSwitchData = processor.UseContextSwitchData();
processor.Process();
double WaitDurationInMs;
foreach (IContextSwitch cSwitch in myContextSwitchData.Result.ContextSwitches)
{
    IContextSwitchIn switchin = cSwitch.SwitchIn;

    if (switchin.WaitTime.HasValue)
    {
        WaitDurationInMs += switchin.WaitTime.Value.TotalMilliseconds;
    }
}

但显然 switchin.WaitTime 值远不及 WPA 打印的任何线程等待时间。我怎样才能得到一个线程 its

等待时间（线程被阻塞）
就绪时间（线程在就绪队列中等待运行）
CPU 时间（线程运行宁在一个 CPU 上）

一个如何做到这一点的例子会很好。此外，WPA 和 TraceProcessor 的上下文切换事件编号似乎有很大偏差。我想我需要了解一些内部机制，这些事件需要如何关联。

Answer 1

我找到了相应的条目。您需要在 ITraceProcessor 的实例上调用扩展方法 .UseCpuSchedulingData()，然后在 ThreadActivity 中获取 CPU/Ready 和 Wait 数据以及调用堆栈，就像在 WPA 中一样。

我准备了一个小示例，它通过 etl 文件中的进程 ID 打印 CPU 和所有线程的等待时间总和：

C>ContextSwitchParsing.exe test.etl
PID:  Idle, CPU: 435395.380084 ms Wait:                0 ms
PID: 18272, CPU: 18389.592761 ms Wait:    133794.380307 ms
PID:  3892, CPU:  5156.316266 ms Wait:   1029236.568333 ms
PID: 16876, CPU:  2861.243413 ms Wait:    174568.161760 ms
PID: 10120, CPU:  2812.669957 ms Wait:     30600.500853 ms
PID: 24808, CPU:  1771.803843 ms Wait:      7445.196940 ms
PID:  1316, CPU:  1690.323850 ms Wait:   1064952.353463 ms
PID:     4, CPU:  1641.261310 ms Wait:   1251175.067399 ms
PID: 15436, CPU:  1438.144470 ms Wait:    286545.316703 ms
PID: 32788, CPU:   541.485469 ms Wait:      1566.614792 ms

这与 WPA 的输出非常同步

下面是源代码。您需要添加对 Nuget 包的引用： Microsoft.Windows.EventTracing.Processing.All 这将消失并解析为一堆依赖的 nuget 包。

using Microsoft.Windows.EventTracing;
using Microsoft.Windows.EventTracing.Cpu;
using System;
using System.Collections.Generic;
using System.Linq;

namespace ContextSwitchParsing
{
    class Program
    {
        static void Main(string[] args)
        {
            if(args.Length ==0)
            {
                Console.WriteLine("Enter an ETL file Name to process");
                return;
            }

            string fileName = args[0];
            new Program().Run(fileName);
        }

        class CpuWait
        {
            public decimal CPUTimeInMs { get; set; }
            public decimal WaitTimeInMs { get; set; }
        }

        enum ProcessId
        {
            Idle =0,
        }

        private void Run(string fileName)
        {
            using ITraceProcessor processor = TraceProcessor.Create(fileName, new TraceProcessorSettings
            {
                AllowLostEvents = true
            });

            IPendingResult<ICpuSchedulingDataSource> schedulingResult = processor.UseCpuSchedulingData();
            processor.Process();

            Dictionary<ProcessId, CpuWait> cpuAndWaitPerProcess = new Dictionary<ProcessId, CpuWait>();

            foreach(ICpuThreadActivity activity in schedulingResult.Result.ThreadActivity)
            {
                if (activity.Process == null)
                {
                    continue;
                }

                ProcessId pid = (ProcessId)activity.Process.Id;

                if ( !cpuAndWaitPerProcess.TryGetValue(pid, out CpuWait cpuAndWait) )
                {
                    cpuAndWait = new CpuWait();
                    cpuAndWaitPerProcess.Add(pid, cpuAndWait);
                }

                cpuAndWait.CPUTimeInMs += activity.Duration.Duration.TotalMilliseconds;

                if( activity.WaitingDuration.HasValue )
                {
                    cpuAndWait.WaitTimeInMs += activity.WaitingDuration.Value.TotalMilliseconds;
                }
            }


            KeyValuePair<ProcessId,CpuWait>[] byCpuDescending = cpuAndWaitPerProcess.OrderByDescending(x => x.Value.CPUTimeInMs).ToArray();

            foreach(var top in byCpuDescending.Take(10))
            {
                Console.WriteLine($"PID: {top.Key,5}, CPU: {top.Value.CPUTimeInMs,12} ms Wait: {top.Value.WaitTimeInMs,16} ms");
            }
        }
    }
}

这非常有效，而且解析起来非常高效。它在幕后使用 ContextSwitch 数据源，但您需要了解相当多的内部知识才能理解它。

这个库的一个绝妙技巧是它按处理器对所有上下文切换事件进行分组，因为上下文切换总是发生在一个处理器上，因此您可以处理按 CPU 分组的时间排序的所有上下文切换事件。在内部它使用 MinHeap 的巧妙组合，声明为

MinHeap<IEnumerator, CSwitchIEnumeratorByTimeComparer>

其中包含分组。

一旦到达一个新的处理器，Minheap 就会枚举所有事件并创建一个数据树，然后按时间排序使用该数据树，直到没有事件存在，然后下一个处理器分组被“扩展”。

除此之外，我真的很喜欢时间戳的简洁设计，它可以根据您的需求直接转换为毫、微、纳秒小数或 DateTimeOffset 值。此外，大小类型的明确定义声明了您在强类型中可能需要的所有内容，这使得 crystal 清楚您获得的单位值：

    public readonly struct DataSize : IEquatable<DataSize>, IComparable<DataSize>, IComparable
    {
        public static readonly DataSize Zero;
        public static readonly DataSize MinValue;
        public static readonly DataSize MaxValue;

        public DataSize(long bytes);

        public decimal TotalMebibytes { get; }
        public decimal TotalKibibytes { get; }
        public decimal TotalTerabytes { get; }
        public decimal TotalGigabytes { get; }
        public decimal TotalMegabytes { get; }
        public decimal TotalKilobytes { get; }
        public long Bytes { get; }
        public decimal TotalGibibytes { get; }
        public decimal TotalTebibytes { get; }

        public static DataSize FromBytes(decimal bytes);
        public static DataSize FromBytes(long bytes);
        public static DataSize FromGibibytes(long gibibytes);
        public static DataSize FromGibibytes(decimal gibibytes);
        public static DataSize FromGigabytes(decimal gigabytes);
        public static DataSize FromGigabytes(long gigabytes);
        public static DataSize FromKibibytes(long kibibytes);
        public static DataSize FromKibibytes(decimal kibibytes);
        public static DataSize FromKilobytes(long kilobytes);
        public static DataSize FromKilobytes(decimal kilobytes);
        public static DataSize FromMebibytes(long mebibytes);
        public static DataSize FromMebibytes(decimal mebibytes);
        public static DataSize FromMegabytes(long megabytes);
        public static DataSize FromMegabytes(decimal megabytes);
        public static DataSize FromTebibytes(long tebibytes);
        public static DataSize FromTebibytes(decimal tebibytes);
        public static DataSize FromTerabytes(long terabytes);
        public static DataSize FromTerabytes(decimal terabytes);
        public static DataSize Max(DataSize first, DataSize second);
        public static DataSize Min(DataSize first, DataSize second);
        public int CompareTo(object other);
        public int CompareTo(DataSize other);
        public override bool Equals(object other);
        public bool Equals(DataSize other);
        public override int GetHashCode();
        public string ToString(bool useBinaryPrefixes);
        public override string ToString();

        public static DataSize operator +(DataSize left, DataSize right);
        public static DataSize operator -(DataSize left, DataSize right);
        public static bool operator ==(DataSize left, DataSize right);
        public static bool operator !=(DataSize left, DataSize right);
        public static bool operator <(DataSize left, DataSize right);
        public static bool operator >(DataSize left, DataSize right);
        public static bool operator <=(DataSize left, DataSize right);
        public static bool operator >=(DataSize left, DataSize right);
    }

到目前为止，这是 ETW 库之一，教科书设计了如何在保持出色性能的同时实现清晰易用的 API。

线程等待时间

Thread Wait Times

c#

etw

.net-traceprocessing