ASP.NET and System.Diagnostics tracing - have I missed something, or is this a bad idea?

Question

For various common reasons I wanted to use tracing for my ASP.NET application. Especially since I found out about the possibility to use the Service Trace Viewer tool which allows you to examine your traces in a powerful way.

Since I had never used this trace thing before, I started stuying it. After a while of Google, SO and MSDN I finally have a good idea of how things work. But I also found one very distrubing thing.

When using trace in ASP.NET applications it makes a lot of sense to group the trace messages together by web requests. Especially since one of the reasons I want to use it is for studying performance problems. The above mentioned tool also supports this by using <Corrleation> tags in the generated XML files. Which in turn come from System.Diagnostics.Trace.CorrelationManager. It also allows other nice features like Activity starting/stopping, which provides an even better grouping of trace messages. Cool, right?

I though so too, until I started inspecting where the CorrelationManager actually lived. After all - it was a static property. After some playing around with Reflector I found out something horrifying - it's stored in CallContext! Which is the kind of thing we shouldn't be using in ASP.NET, right?

So... am I missing something here? Is tracing really fundamentally flawed in ASP.NET?

Added: Emm, I'm kinda on the verge of rewriting this stuff myself. I still want to use the neat tool for exploring the traces. Any reason I shouldn't do this? Perhaps there is something better yet? It would be really nice if I got some answers soon. :)

Added 2: A colleague of mine confirmed that this is not just a theoretical issue. He has observed this in the system he's working on. So it's settled. I'm going to build a new little system that does things just the way I want it to. :)

Added 3: Wow, cool... the guys at Microsoft couldn't find anything wrong with using Correlation Manager in ASP.NET. So apparently we're not getting a fix for this bug after all...

Answer 1

Hello,

You raise a very interesting question. After looking at Reflector, I also see that CorrelationManager is using the CallContext to store the activity id. I have not worked with tracing much, so I can't really speak on behalf of what types of activities it tracks, but if it tracks a single activity across the entire life cycle of a page request, per the article you referenced above, there is a possibility that the activity id could become disassociated with the actual activity. This activity would appear to die halfway through.

HttpContext would seem ideal for tracking an entire page request from beginning to finish, since it will be carried over even if the execution changes to a different thread. However, the HttpContext will not be transferred to your business objects, where as the CallContext would. On a side note, I saw that CallContext can also be transferred when using remoting between client and server apps which is pretty nifty, but in the case of tracking the website, this would not really be all that useful.

If you haven't already, check out this guy's site. The issue described in this article isn't specifically the same issue that Cup(Of T) article mentioned, but it's still pretty interesting. He also provides several very informative links on the page that describe components of the CorrelateionManager.

Unfortunately, I don't really have an answer to your question, but I definitely find the topic interesting and will continue looking into it. So please update this post as you learn more. I'm curious to see what you or others (hopefully someone out there can shed some light on the topic) find while looking into this.

Anyway, good luck. I'll talk to some of the peeps at my work about this and post more later if I find anything.

Chris

Answer 2

OK, so this is how it ended.

My colleague called Microsoft and reported this bug to them. Being certified partners means we get access to some more prioritized fixing queue or something... don't know that stuff. Anyway, they're working on it. Hopefully we'll see a patch soon. :)

In the mean time I've created my own little tracing class. It doesn't support all the bells and whistles that the default trace framework does, but it's just what I need. :) More specifically:

• It writes to the same XML format as the default XmlWriterTraceListener so I can use the tool to analyze the logs.
• It has a built in log rotation - something my colleague had to do himself on top of XmlWriterTraceListener.
• The actual logging is deferred to another thread so performance can be measured more accurately.
• Correlations are now stored in HttpContext.Items so ASP.NET threading peculiarities don't affect it.

Happy end, I hope. :)