我如何收听 TPL TaskStarted/TaskCompleted ETW 事件

Question

我有兴趣收听 ETW（Windows 的事件跟踪）TPL 事件，特别是我想知道 Task 何时开始以及何时停止。

这是我用来测试的示例程序：

   using System;
   using System.Collections.Generic;
   using System.Diagnostics.Tracing;
   using System.Linq;
   using System.Text;
   using System.Threading;
   using System.Threading.Tasks;

   namespace ConsoleApplication10
   {
      class Listener : EventListener
      {
         private static readonly Guid tplGuid = new Guid("2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5");

         protected override void OnEventSourceCreated(EventSource eventSource)
         {
            Console.WriteLine("Got guid: " + eventSource.Guid);
            EnableEvents(eventSource, EventLevel.LogAlways);
         }

         protected override void OnEventWritten(EventWrittenEventArgs eventData)
         {
            Console.WriteLine("Event: " + eventData.EventId);
         }
      }

      class Program
      {
         static void Main(string[] args)
         {
            using (var listener = new Listener())
            {
               Action doIt = null;
               doIt = () =>
               {
                  Thread.Sleep(1000);
                  Console.Write('.');
                  Task.Run(doIt);
               };
               Task.Run(doIt);

               Parallel.Invoke(() => Console.WriteLine("invoke"));

               Console.Read();
            }
         }
      }
   }

我机器上的示例输出如下：

Got guid: 8e9f5090-2d75-4d03-8a81-e5afbf85daf1
Got guid: 2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5
Event: 3
invoke
Event: 4
.......

所以 Invoke 方法导致事件触发，但任务触发 none。查看任务源（例如 reference source），代码看起来与 Parallel.Invoke 事件的触发方式没有什么不同。

以上有什么问题，或者，我如何收听 TaskStarted 和 TaskCompleted 事件（或 any 与此相关的任务相关事件）？

Answer 1

你的问题促使我调查 ETW（我已经想调查了一段时间）。我能够使用 Microsoft.Diagnostics.Tracing.TraceEvent NuGet library 和简单的以下代码捕获 "task start" 和 "task end" ：

private static void Main(string[] args)
{
    Task.Run(() =>
    {
        using (var session = new TraceEventSession("TplCaptureSession"))
        {
            session.EnableProvider(new Guid("2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5"),
                                   TraceEventLevel.Always);

            session.Source.Dynamic.AddCallbackForProviderEvent("System.Threading.Tasks
                                                               .TplEventSource",
                "TaskExecute/Start", @event =>
                {
                    Console.WriteLine("Inside Task Started");
                });

            session.Source.Dynamic.AddCallbackForProviderEvent("System.Threading.Tasks
                                                   .TplEventSource", 
                "TaskExecute/Stop", @event =>
                {
                    Console.WriteLine("Inside Task Stopped");
                });

            session.Source.Process();
        }
    });

    var task = Task.Run(async () =>
    {
        await Task.Delay(20000);
    });

    task.Wait();
}

基本上发生的事情是：

我们使用 TraceEventSession 开始新的实时事件捕获会话，我们在其中传递它 TraceEventLevel.Always 以打印出所有消息（我们可以将其缩小到 TranceEventLevel.Information , 但对于示例，我选择了 all).
我们通过将其 Guid 传递给 session.EnableProvider 来启用 TplEventSource 提供程序。
我们注册一个回调，一旦 TplEventSource（显然是 TPL 的事件源）触发 TaskExecute/Start 或 TaskExecute/Stop 事件（采取来自 reference source)
我们在进入活动后打印出来。

请注意，我使用 Task.Run 只是因为 session.Source.Process() 是一个阻塞调用，我希望它在后台运行。

Answer 2

Here is an example 我编写的仅使用 BCL 侦听 TPL ETW 事件的代码。

part that tripped me up 是事实，您需要运行此代码：

// Cause the type initializer for System.Threading.Tasks.TplEtwProvider to run.
// Otherwise async method builders starting events will be missed.
Type.GetType("System.Threading.Tasks.TplEtwProvider, mscorlib", true).GetField("Log").GetValue(null);

否则，一切似乎都按照您期望的方式进行。不需要 third-party 个库！

Answer 3

基于对我不起作用，因为事件名称似乎不同，我想出了一个类型安全且不使用魔术 guid 或字符串的解决方案：

using System;
using System.Diagnostics;
using System.Threading.Tasks;
using Microsoft.Diagnostics.Tracing;
using Microsoft.Diagnostics.Tracing.Parsers;
using Microsoft.Diagnostics.Tracing.Parsers.Tpl;
using Microsoft.Diagnostics.Tracing.Session;

...

Task.Run(() =>
{
    using (var session = new TraceEventSession("TplCaptureSession"))
    {
        session.EnableProvider(TplEtwProviderTraceEventParser.ProviderGuid, TraceEventLevel.Always);

        var parser = new TplEtwProviderTraceEventParser(session.Source);
parser.AddCallbackForEvent<TaskStartedArgs>(
            null,
            @event =>
            {
                Console.WriteLine($"Task {@event.TaskID} started by {@event.OriginatingTaskID}");
            });

        parser.AddCallbackForEvent<TaskCompletedArgs>(
            null,
            @event =>
            {
                Console.WriteLine($"Task {@event.TaskID} completed");
            });

        session.Source.Process();
    }
});

为了完整起见，这里列出了我看到的由 System.Threading.Tasks.TplEventSource 来源生成的事件名称：

AwaitTaskContinuationScheduled/Send
DebugFacilityMessage
DebugFacilityMessage1
调试消息
EventSourceMessage
ForkJoin/Start
ForkJoin/Stop
IncompleteAsyncMethod
Invoke/Start
Invoke/Stop
Loop/Start
Loop/Stop
清单数据
新ID
RunningContinuation
RunningContinuationList
SetActivityId
任务完成
TaskScheduled/Send
任务已启动
TaskWait/Send
任务等待继续完成
TaskWaitContinuationStarted
任务等待结束
TraceOperationBegin
TraceOperationEnd
TraceOperationRelation
TraceSynchronousWorkBegin
TraceSynchronousWorkEnd

我如何收听 TPL TaskStarted/TaskCompleted ETW 事件

How do I listen to TPL TaskStarted/TaskCompleted ETW events

.net

c#

etw

task-parallel-library