Separating Logging Code from C# Objects

Currently I have a custom built static logging class in C# that can be called wit开发者_开发百科h the following code:

EventLogger.Log(EventLogger.EventType.Application, string.Format("AddData request from {0}", ipAddress));

When this is called it simply writes to a defined log file specified in a configuration file.

However, being that I have to log many, many events, my code is starting to become hard to read because all of the logging messages.

Is there an established way to more or less separate logging code from objects and methods in a C# class so code doesn't become unruly?

Thank you all in advance for your help as this is something I have been struggling with lately.

I like the AOP Features, that PostSharp offers. In my opinion Loggin is an aspect of any kind of software. Logging isn't the main value an application should provide.

So in my case, PostSharp always was fine. Spring.NET has also an AOP module which could be used to achieve this.

The most commonly used technique I have seen employs AOP in one form or another.

PostSharp is one product that does IL weaving as a form of AOP, though not the only way to do AOP in .NET.

A solution to this is to use Aspect-oriented programming in which you can separate these concerns. This is a pretty complex/invasive change though, so I'm not sure if it's feasible in your situation.

I used to have a custom built logger but recently changed to TracerX. This provides a simple way to instrument the code with different levels of severity. Loggers can be created with names closely related to the class etc that you are working with

It has a separate Viewer with a lot of filtering capabilities including logger, severity and so on.

http://tracerx.codeplex.com/

There is an article on it here: http://www.codeproject.com/KB/dotnet/TracerX.aspx

If your primary goal is to log function entry/exit points and occasional information in between, I've had good results with an Disposable logging object where the constructor traces the function entry, and Dispose() traces the exit. This allows calling code to simply wrap each method's code inside a single using statement. Methods are also provided for arbitrary logs in between. Here is a complete C# ETW event tracing class along with a function entry/exit wrapper:

using System;
using System.Diagnostics;
using System.Diagnostics.Tracing;
using System.Reflection;
using System.Runtime.CompilerServices;

namespace MyExample
{
    // This class traces function entry/exit
    // Constructor is used to automatically log function entry.
    // Dispose is used to automatically log function exit.
    // use "using(FnTraceWrap x = new FnTraceWrap()){ function code }" pattern for function entry/exit tracing
    public class FnTraceWrap : IDisposable
    {
        string methodName;
        string className;

        private bool _disposed = false;

        public FnTraceWrap()
        {
            StackFrame frame;
            MethodBase method;

            frame = new StackFrame(1);
            method = frame.GetMethod();
            this.methodName = method.Name;
            this.className = method.DeclaringType.Name;

            MyEventSourceClass.Log.TraceEnter(this.className, this.methodName);
        }

        public void TraceMessage(string format, params object[] args)
        {
            string message = String.Format(format, args);
            MyEventSourceClass.Log.TraceMessage(message);
        }

        public void Dispose()
        {
            if (!this._disposed)
            {
                this._disposed = true;
                MyEventSourceClass.Log.TraceExit(this.className, this.methodName);
            }
        }
    }

    [EventSource(Name = "MyEventSource")]
    sealed class MyEventSourceClass : EventSource
    {
        // Global singleton instance
        public static MyEventSourceClass Log = new MyEventSourceClass();

        private MyEventSourceClass()
        {
        }

        [Event(1, Opcode = EventOpcode.Info, Level = EventLevel.Informational)]
        public void TraceMessage(string message)
        {
            WriteEvent(1, message);
        }

        [Event(2, Message = "{0}({1}) - {2}: {3}", Opcode = EventOpcode.Info, Level = EventLevel.Informational)]
        public void TraceCodeLine([CallerFilePath] string filePath = "",
                                  [CallerLineNumber] int line = 0,
                                  [CallerMemberName] string memberName = "", string message = "")
        {
            WriteEvent(2, filePath, line, memberName, message);
        }

        // Function-level entry and exit tracing
        [Event(3, Message = "Entering {0}.{1}", Opcode = EventOpcode.Start, Level = EventLevel.Informational)]
        public void TraceEnter(string className, string methodName)
        {
            WriteEvent(3, className, methodName);
        }

        [Event(4, Message = "Exiting {0}.{1}", Opcode = EventOpcode.Stop, Level = EventLevel.Informational)]
        public void TraceExit(string className, string methodName)
        {
            WriteEvent(4, className, methodName);
        }
    }
}

Code that uses it will look something like this:

public void DoWork(string foo)
{
    using (FnTraceWrap fnTrace = new FnTraceWrap())
    {
        fnTrace.TraceMessage("Doing work on {0}.", foo);
        /*
        code ...
        */
    }
}

To make the code readable, only log what you really need to (info/warning/error). Log debug messages during development, but remove most when you are finished. For trace logging, use AOP to log simple things like method entry/exit (if you feel you need that kind of granularity).

Example:

public int SomeMethod(int arg)
{
   Log.Trace("SomeClass.SomeMethod({0}), entering",arg);  // A
   if (arg < 0)
   {
      arg = -arg;
      Log.Warn("Negative arg {0} was corrected", arg);    // B
   }
   Log.Trace("SomeClass.SomeMethod({0}), returning.",arg);  // C
   return 2*arg;
}

In this example, the only necessary log statement is B. The log statements A and C are boilerplate, logging that you can leave to PostSharp to insert for you instead.

Also: in your example you can see that there is some form of "Action X invoked by Y", which suggests that a lot of your code could in fact be moved up to a higher level (e.g. Command/Filter).

Your proliferation of logging statements could be telling you something: that some form of design pattern could be used, which could also centralize a lot of the logging.

void DoSomething(Command command, User user)
{
   Log.Info("Command {0} invoked by {1}", command, user);
   command.Process(user);
}

I think it is a good option to implement something similar to filters in ASP.NET MVC. This is implement with the help of attributes and reflection. You mark every method you want to log in a certain way and enjoy. I suppose there might be a better way to do it, may be with the help of Observer pattern or something but as long as I thought about it I couldn't think of something better.

Basically such problems are called cross-cutting concerns and can be tackled with the help of AOP.

I also think that some interesting inheritance schema can be applied with log entities at the base but I would go for filters