Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

EventSource tracing with correlated activity id

I've started using ETW and the out-of-process Semantic Logging Block from Entlib 6. When I use async/await, the CurrentThreadActivityId is not set on the continuation thread and the TPL framework does not log a transfer event. This makes it extremely difficult to perform end-to-end tracing.

According to Microsoft's documentation, the TPL framework is supposed to log a transfer event and generate a new activityid, but I can't seem to get it to work.

Documentation from Entlib 6

Here's a small example showing the problem:

To log TPL events, I'm using the following:

<eventSource name="System.Threading.Tasks.TplEventSource" level="Informational" matchAnyKeyword="1"/>

And here my test code:

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

namespace AsyncContextTest
{
    class Program
    {
        static Guid _activityId = Guid.NewGuid();

        static void Main(string[] args)
        {
            EventSource.SetCurrentThreadActivityId(_activityId);
            Console.WriteLine(EventSource.CurrentThreadActivityId);
            Task t = Task.Run(async () => await DoStuffAsync());
            Console.WriteLine(EventSource.CurrentThreadActivityId);

            Console.Read();
        }

        public static async Task DoStuffAsync()
        {
            var x = "one,two,three".Split(',');
            Console.WriteLine(EventSource.CurrentThreadActivityId);
            await Task.Delay(1000);
            Console.WriteLine(EventSource.CurrentThreadActivityId);
            var y = String.Join(",", x);

            Console.WriteLine("Done");

        }
    }
}

Results

334540cc-ccb1-4196-8587-815abf237e4c
334540cc-ccb1-4196-8587-815abf237e4c
00000000-0000-0000-0000-000000000000
00000000-0000-0000-0000-000000000000
Done

Does anyone have a simple example showing the proper way to do end to end tracing with ETW and async/await?

EDIT:

I was able to get this working properly with an in-process listener, but not with the out-of-process listener. Nothing is logged from TPL.

like image 316
Chris Gessler Avatar asked Nov 11 '22 00:11

Chris Gessler


1 Answers

Change the configuration to use the event source's GUID instead of the name.

<eventSource id="2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5" level="Informational" />

Output will look like:

605e615a-c849-4ee7-95b8-e6677f945c3f
605e615a-c849-4ee7-95b8-e6677f945c3f
00000001-0001-0000-0c22-0000ffdcd7b5
00000002-0001-0000-0c22-0000ffdcd7b5
Done

Does anyone have a simple example showing the proper way to do end to end tracing with ETW and async/await?

Still looking...

like image 107
Chris Gessler Avatar answered Nov 14 '22 22:11

Chris Gessler