Logging with TracerX

Loggers

TracerX uses the Log4Net concept of a hierarchy of Loggers. All logging is done through instances of the Logger class. Each Logger has a name that appears in the "Logger" column in the viewer. Each Logger should represent a category of logging within your application such as "Reporting" or "Configuration".

You must decide how many Loggers to create and what to name them. One approach is to create a Logger for each class in your app like this.

using TracerX;

class CoolClass
{
        private static readonly Logger Log = Logger.GetLogger("CoolClass");

        // etc.
} 

The static method Logger.GetLogger() is the only way to create Loggers in your code. You can pass it a Type or a string. A Type is just converted to its fully qualified name and passed on to the string overload. It creates a Logger with the specified name, which appears in the viewer. All subsequent calls with the same name return the same instance, so code in several different files can use the same Logger if desired.

Logger Tree

Logger names can contain periods, such as "MyNamespace.CoolClass". TracerX uses the period-separated substrings of the names to create a tree of Loggers. For example, "A.B" is the parent of "A.B.Anything". Note that "A.B" need not exist for "A.B.C" to exist. It does't matter what order the Loggers are created in. TracerX inserts each Logger into the appropriate place in the tree when it is created.

The root of the tree is always the pre-defined static property Logger.Root. Every Logger you create will be a descendant of the Root Logger. You can do all your logging through Logger.Root without ever calling GetLogger(), but I don't recommend that approach since it leaves you with no ability to filter the output by Logger name in the viewer or to control the amount of logging done by different areas of your code at run-time.

Trace Levels

Each Logger instance has a property called FileTraceLevel that controls which log messages are written to the output file by that Logger. If this property is set to TraceLevel.Undefined, the effective FileTraceLevel for that logger is inherited from the parent logger, all the way up to Root if necessary. The initial FileTraceLevel for all Loggers that you create with GetLogger is Undefined. Therefore, you can set the effective FileTraceLevel of all Loggers by setting Logger.Root.FileTraceLevel unless you have explicitly set the FileTraceLevel of a given Logger.

The enum TracerX.TraceLevel defines the following values (from lowest to highest) that you can assign to the Logger.FileTraceLevel property.
  • Undefined
  • Off
  • Fatal
  • Error
  • Warn
  • Info
  • Debug
  • Verbose

Setting Logger.FileTraceLevel to higher values causes that Logger to generate more output. Setting it to Undefined causes the effective value to be inherited from the parent Logger. The Root logger cannot have an Undefined trace level.

How to Log a Message

Assuming you have a Logger instance named Log, you can use it to log messages with statements like this.

Log.Info("A string logged at the Info level.");
Log.Debug("Several objects at Debug level ", obj1, obj2); 


The trace level of the message is implied by the method you call (Log.Info(), Log.Debug(), etc.). A given call only writes to the output file if the corresponding trace level is enabled for that Logger. For example, the above call to Log.Info only generates output if Log.FileTraceLevel is Info or higher (i.e. Debug or Verbose). Put another way, setting Log.FileTraceLevel to a given TraceLevel value enables all logging statements at or below that level for that Logger (and any child Loggers whose FileTraceLevel is TraceLevel.Undefined).

You can pass any number of arguments to the above methods. The arguments need not be strings. If the method's trace level is enabled, each argument is converted to a string and concatenated to form the message that appears in viewer's Text column (see Custom Object Rendering). You should avoid calling ToString() yourself since this wastes processing if the message doesn't get logged due to its trace level.

Each trace level also has a version that uses the same semantics as string.Format() like this.

Log.VerboseFormat("obj1 is {0}.", obj1); 

How to Log a Method Call

Logging your method calls enables several powerful features in the viewer, such as the ability to collapse/expand the output from a given method call and to view/walk the call stack. To log calls to a given method, wrap the contents of the method in a using block like this (this assumes you've created a Logger named Log).

private void YourMethod()
{
    using (Log.InfoCall())
    {
        // Other code goes here!
    }
} 

As before, the trace level is implied by the name of the Logger method (e.g. Log.InfoCall(), Log.DebugCall(), etc.). If that trace level is enabled, the following occurs.
  1. TracerX looks up the name of the calling method on the call stack (i.e. "YourMethod").
  2. A message like "YourMethod: entered" is logged.
  3. Indentation is increased for any logging done by the calling thread inside the "using" block.
  4. The viewer displays "YourMethod" in the Method column for any logging inside the "using" block.
  5. An object is returned whose Dispose method logs a message like "YourMethod: exiting" and restores the previous indentation and method name for the thread.
Looking up the calling method on the call stack does take a bit of processing, but is negligible in most cases and always logs the correct method name even if you change it (e.g. by refactoring). If your method is called very frequently (many times per second), it might be worth passing the method name as a string to InfoCall(), DebugCall(), etc. This is more error-prone, but avoids the stack lookup. Two additional reasons to pass the method name as a string are...
  1. You plan to obfuscate your code.
  2. You want to simulate a method call in an "if" statement, "for" loop, or other block.
Just FYI, all calls to InfoCall(), DebugCall(), etc. return the same object. If the trace level for such a call is not enabled, the call returns null.

Last edited Dec 30, 2007 at 4:30 PM by MarkLTX, version 2

Comments

No comments yet.