Tracer activates LogEvents on other threads.

Topics: Logging Application Block
Apr 19, 2007 at 10:56 PM
Perhaps it is my lack of understanding in how the Tracer works but for some reason when I enable a Tracer I start getting events from other threads. The ActivityId on the events from the other threads is Guid.Empty but they are being logged anyway. So I am puzzeled. Why is the Tracer category being injected into the other thread's LogEvents when they are not participating in the activity?

My configuration can be summerized as follows:
Category Sources:
Connect - All
General - Information

Special Sources:
Unprocessed Category - Information

The events being generated by the background threads are Verbose and fall into the Unprocessed Category.
The Tracer category is Connect.
The events from the background threads are only logged while the Tracer is active. As soon as Dispose is called on the Tracer they stop. The background events are being logged to the Connect category's Trace Listener.

Can someone please explain this behaviour to me?
Apr 19, 2007 at 11:42 PM
Edited Apr 19, 2007 at 11:48 PM
I'm sorry, my bug. Apparently you can't keep a Tracer alive over multiple call contexts. Basically I was making an asynchronous call. I created the Tracer before calling BeginXXX and then disposed it after calling EndXXX in the callback. The idea was to match up the BeginXXX and EndXXX activities. This does not work because the ActivityId on Trace.CorrelationManager is set to Guid.Empty after leaving the function where I called BeginXXX. Hence I was inadvertantly enabling the background thread traces. The best I can do is run two Tracer contexts, one for the BeginXXX and one for the EndXXX. I can preserve the ActiviteId between the contexts by passing it through the asynch state object.
Apr 20, 2007 at 12:47 AM
Edited Apr 20, 2007 at 1:29 AM
Ah, nutz, it is an issue. Background events are definitely enabled while a Tracer is active. Ignore my second post.

I've checked and it seems that the Trace.CorrelationManager.LogicalOperationStack is shared between threads. At least if you StartLogicalOperation on the UI thread it shows up on the background threads as well. The only thing that is thread unique is ActivityId.

Question: If the UI thread creates the background thread do they share the same CallContext? Will investigate tomorrow...
Apr 20, 2007 at 5:26 PM
And the truth will set you free.

Apparently, a logical context is passed onto any threads you create unless you specifically suppress it by calling ExecutionContext.SuppressFlow() before calling Thread.Start(). This is why the Trace.CorrelationManager.LogicalOperationStack was being shared between threads. You learn something new everyday.