Jason Boyd
Jason Boyd

Reputation: 7029

ActivityId missing from ETW events published from different threads

So I have a WCF service that I am hosting in a console application on my dev machine. I am running PerfView on the same machine to collect ETW (Event Tracing for Windows) events. The WCF service makes use of the TPL (Task Parallel Library) and I am trying to correlate ETW events across all threads for the entire lifetime of a WCF request. I am talking strictly on the server not across the client and the server. However, when I look at the events in PerfView and I filter the view down to only those events from my custom EventSource only the events on some of the threads have an ActivityId. For any given thread either all events have an ActivityId or none of the events do. Also, none of the events have a RelatedActivityId.

This link pertains to the Semantic Logging Application Block (SLAB) but in it they mention that:

When using TPL Tasks, each thread gets its own activity ID and the TPL scheduling code automatically publishes transfer events that contain the ActivityId and RelatedActivityId values. These can be used to correlate related events.

That does not seem to be the case at all for me. Not only do I not see any transfer events to correlate activity ids but in many cases, as I mentioned before, the activity ids are missing altogether.

According to this SO answer: https://stackoverflow.com/a/27620321/1937249:

If you use out of process listeners, then there is bug, that TPL configuration by name not working and GID shall be used instead: https://slab.codeplex.com/workitem/62

So I tried adding the event source's GUID to PerfView's 'Additional Providers' instead of its name like this:

enter image description here

It did not make a difference, though. My events were published but many of them were still missing their ActivityId and all the events were missing their RelatedActivityId.

One last thing that may be relevant, I am using the Microsoft.Diagnostics.Tracing namespace in the Microsoft.Diagnostics.Tracing.EventSource NuGet package rather than the System.Diagnostics.Tracing that is built into the framework.

EDIT

Here is an image showing all the event types that were captured from the TplEventSource. I assume that means the TplEventSource is enabled. It is not clear to me if I should be seeing a 'transfer event' in the list or if one of the events should have a keyword or other field that indicates it was a transfer. If there is supposed to be an actual 'transfer event' I do not see anything like that in the list.

enter image description here

PerfView Output

Here is a picture of the event list from my custom EventSource for a single WCF request. You can see that the request starts on thread id 10,724. Every event on that thread has an ActivityId. 'Asi-Geoservices/StartAuthenticateRequest/Start' makes an asynchronous database call and the application resumes on thread 8,268. None of the events on thread 8,268 have an ActivityId. 'Asi-Geoservices/StartServiceProviderRequest/Start' makes an asynchronous HTTP request and the application resumes on thread 11,764 where, once again, each event on this thread has an ActivityId. After the 'Asi-Geoservices/StartServiceProviderRequest/Stop' another asynchronous database call is made and the application resumes on thread 8,268 again where the request is ultimately completed, but this time every event on the thread now has an ActivityId.

enter image description here

Upvotes: 2

Views: 1032

Answers (0)

Related Questions