new Tracer("OperationName") and Category Sources

Topics: Logging Application Block
Dec 18, 2012 at 9:45 PM

Hello,

This is something that confused me since EntLib 3.0. If you start a new logical operation context by:

using (new Tracer("OerationName))
{
      Tracer.Write("Some Message");
}

it seems that enterprise library expects that a category source is configured for OperationName. Is this behaviour by design or am I missing a clue? If this is indeed by design it looks like a lot of categroy sources will be needed for even a medium application.

Thanks in advance.

Kind reagrds,

Mrs. Wilke Jansoone

 

Dec 19, 2012 at 2:26 AM
Edited Dec 19, 2012 at 2:28 AM

Yes, this behavior is by design.  See Tracing Activities and Propagating Context Information for a description of the behavior.

In terms of categories, you can define a category for every logical operation if you wish.  However, you don't need to define a category for every logical operation if you don't want to.  What you can do is use the special sources.  

One option is to just define the allEvents special source.  This will cause all categories to be sent to the configured trace listener:

        <specialSources>
            <allEvents switchValue="All" name="All Events">
                <listeners>
                    <add name="Flat File Trace Listener" />
                </listeners>
            </allEvents>
            <notProcessed switchValue="All" name="Tracer" />
            <errors switchValue="All" name="Logging Errors & Warnings">
                <listeners>
                    <add name="Error Flat File Trace Listener" />
                </listeners>
            </errors>
        </specialSources>

Another option would be to configure your "regular" category and then use the notProcessed special source to handle the "operation" categories:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <configSections>
        <section name="loggingConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.LoggingSettings, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" requirePermission="true" />
    </configSections>
    <loggingConfiguration name="" tracingEnabled="true" defaultCategory="General">
        <listeners>
            <add name="Flat File Trace Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.FlatFileTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
                listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.FlatFileTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
                fileName="application.log" />
        </listeners>
        <categorySources>
            <add switchValue="All" name="General">
                <listeners>
                    <add name="Flat File Trace Listener" />
                </listeners>
            </add>
        </categorySources>
        <specialSources>
            <allEvents switchValue="All" name="All Events" />
            <notProcessed switchValue="All" name="Tracer">
                <listeners>
                    <add name="Flat File Trace Listener" />
                </listeners>
            </notProcessed>
            <errors switchValue="All" name="Logging Errors & Warnings" />
        </specialSources>
    </loggingConfiguration>
</configuration>

Assuming that only logical operation messages will be not configured (and so be "notProcessed") then you can even send all logical operation messages to a different trace listener than "regular" messages.

Also for the record, I think best practice when using the Tracer is to use the TraceManager class:

TraceManager traceManager = EnterpriseLibraryContainer.Current.GetInstance<TraceManager>();
LogWriter logWriter = EnterpriseLibraryContainer.Current.GetInstance<LogWriter>();
            
using (traceManager.StartTrace("Operation1"))
{
    logWriter.Write("my message", "General");
    // or equivalently
    traceManager.LogWriter.Write("my message", "General");
}

Or if you are using dependency injection you could inject the TraceManager (and perhaps also LogWriter) and use those for logging:

public class Processor
{
    private TraceManager traceManager;
    private LogWriter logWriter;

    public Processor(LogWriter logWriter, TraceManager traceManager)
    {
        this.traceManager = traceManager;
        this.logWriter = logWriter;
    }

    public void Process()
    {
        logWriter.Write("my message1", "General");

        using (traceManager.StartTrace("Operation1"))
        {
            logWriter.Write("my message2", "General");
        }
    }
}

--
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to 

Dec 19, 2012 at 9:16 AM

Hello Randy,

First of all I want to thank you for your very swift reply.

The fact that the logging block picks up the "logical operation" name and tries to map it to a category implicitly means that it expects a category source to be defined. In some cases I want to dispatch the trace messages to a specific destination irrespective of the logical operation context. Let's say I want to trace messages originating in the business layer to an application event log with a specific "businesslayer" event source ( a specific business layer trace listener does the dispatching) , although I can implement the specific logic to pick up the logical layer and add it to the list of categories, the logging block will always automatically pick up the logical operation as well and try to map it to a category source (the list of logentry categories contains than two entries, a category equal to the logical operation name and the category added by the custom implementation). Because of the implicit adding of the category the logging block tries to log the message twice, one time to a category that is mapped (logical layer) and one time to a category (logical operation) that is not mapped which will show up as error in the event log (if tracelistener points to event log).

I can circumvent the issue by using; as you pointed out; the notprocessed special source and setting the switchvalue to "warning". In this way the informational trace messages will not be logged twice. This has a couple of drawbacks of course; informational messages with unmapped categories not originating from a tracer will not be mapped as well.

Thank you for the information on the TraceManager, I did not know this class existed.

Kind regards,

Mrs. Wilke Jansoone

 

Dec 19, 2012 at 4:03 PM
Edited Dec 19, 2012 at 4:03 PM

If the out of the box behavior does not suit your needs, then you could create your own custom Tracer class.  For example you could have all tracers also add another category (e.g. "Tracing").  When the LogEntry is created internally you could use an ICollection<string> with the operation as well as any other categories you wish instead of just the operation string.  

Just start with the existing Tracer source code -- this would be quick and easy change.

--
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to 

Dec 19, 2012 at 5:28 PM

Hello Randy,

Indeed I can create a custom Tracer class, the problem lies in the fact that the Tracer depends on the LogWriterImpl class to actually write the logEntries, when this class writes the LogEntry it calls AddTracingCategories which adds a category for the current logical operation (if there is one). This functionality is baked deep in the internals of the logging application block and it seems to me that it can only be changed by modifying the logging block itself (which I'd rather no do for compatability reasons).

I'll just stick to using the notprocessed special source and set the switchvalue to warning, the risk being that informational not category-mapped logentries will go unnoticed.

Thanks again for your advice.

Kind regards,

Mrs. Wilke Jansoone

 

 

Dec 19, 2012 at 6:03 PM

Personally, I don't usually have Unprocessed Category configured since I will usually use predefined constants in code for the category values.  If you do that and set Warn if No Category Match to false then you will avoid "spurious" log entries and only predefined categories will be logged.

If that still doesn't suit your needs then you can either change the block to not use the LogicalOperationStack or create a new LogWriter implementation with the desired functionality and inject that into the Container without touching Enterprise Library source as per this article: Enterprise Library Logging Extensions – Part 3.

--
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to