It's fair to say I have a love hate relationship with Logging. I love when logging can help identify the issue - when it's enough but not too much! But I hate when logging code obfuscates the reason of the code. Go on just think back to all those code bases you have seen where littered with Log.Write statements that were clearly put in as the result of a very pressured debug session - not that you would have ever done this of course...

One of the simple things I like to do early on in projects is build in a capability to 'configurably' log method entry and exit within my code base. With parameter details this is more often than not enough for those times when your 'actual' logging isn't giving you enough to diagnose the issue. This allows me to essentially ignore logging at the start of development, as I can use this approach to help diagnose, and steer my 'actual' logging to make it targeted and useful rather than overly verbose and redundant!

I have blogged about this approachbefore (apparently quite a while ago) - but as there have been some significant breaking changes to Interception in Unity v 3.5 and the Enterprise Library v 6 logging application block, I thought a refresh was in order.

This approach is obviously possible and probably just as easy with other containers and logging tools - so there really is no excuse for random Log.Write statements everywhere!

So lets start from scratch - first we are going to add the NuGet package Unity.Interception which will also bring in the Unity package. We create a container and register a simple test interface and implementation.

UnityContainer container = new UnityContainer();
container.RegisterType<ICommand, TestCommand>(); 

We resolve that and execute our test command:

ICommand command = container.Resolve<ICommand>();
command.Execute(); 

Simple - so now we have a container we can look to add the configurable logging capability we want.
We are going to use Enterprise Library for logging and also the configurable policy - so add EnterpriseLibrary.Logging and
EnterpriseLibrary.PolicyInjection packages.

Enterprise Libarary logging needs to be configured, for flexibility I tend to use the Xml configuration approach using the config tool that comes with the full binary download, but it can also be done using a fluent interface. There is plenty of documentation on getting started with the logging application block. Because in this simple approach we are going to use the static LogWriter we need to bootstrap logging after we have configured it by calling:

Logger.SetLogWriter(new LogWriterFactory().Create()); 

Then we need to change the creation of the container to enable the Interception extension:

UnityContainer container = new UnityContainer();
container.AddNewExtension<Interception>();
container.LoadConfiguration(); 

Note that we are loading our external configuration LoadConfiguration - which at this point it will fail as we haven't yet sorted the Unity config (be patient).

We also need to change our registrations to add our interception behaviour - we are just using a simple interface interceptor here as our code will be all interface driven!

container.RegisterType<ICommand, TestCommand>(
	new InterceptionBehavior<PolicyInjectionBehavior>(),
         new Interceptor<InterfaceInterceptor>()); 

Obviously this could make registrations a bit verbose - so you can push this it into an extension method.

The configuration is the only fiddly bit. Unity has a fluent config api so we could add:

            container.Configure<Interception>()
              .AddPolicy("logging")
              .AddMatchingRule<AssemblyMatchingRule>(
                new InjectionConstructor(
                  new InjectionParameter("Library")))
              .AddCallHandler<LogCallHandler>(
                new ContainerControlledLifetimeManager(),
                new InjectionConstructor(
                  9001, true, true,
                  "start", "finish", true, false, true, 10, 1)); 

after the container construction. This configuration adds a policy (called "logging") with an assembly matching rule that intercepts everything from assembly "Library" and uses the LogCallHander (from the policy injection block) to log before and after (check out the constructor of LogCallHandler to see what all those bools and ints do!). Useful, but ideally we want to be able to drop the policy in without code change.

So using UNity design time configuration - we create the following Unity config section:

<unity xmlns="http://schemas.microsoft.com/practices/2010/unity">
    <sectionExtension type="Microsoft.Practices.Unity.InterceptionExtension.Configuration.InterceptionConfigurationExtension, Microsoft.Practices.Unity.Interception.Configuration" /> 

    <container>
      <extension type="Interception" />
      <interception>
        <policy name="logging">
          <matchingRule name="library" type="AssemblyMatchingRule">
            <constructor>
              <param name="assemblyName" value="Library" />
            </constructor>
          </matchingRule>
          <callHandler name="LogHandler" type="Microsoft.Practices.EnterpriseLibrary.Logging.PolicyInjection.LogCallHandler,Microsoft.Practices.EnterpriseLibrary.PolicyInjection">
            <constructor>
              <param name="eventId" value="9001" />
              <param name="logBeforeCall" value="true" />
              <param name="logAfterCall" value="true" />
              <param name="beforeMessage" value="Before" />
              <param name="afterMessage" value="After" />
              <param name="includeParameters" value="true" />
              <param name="includeCallStack" value="true" />
              <param name="includeCallTime" value="true" />
              <param name="priority" value="3" />
            </constructor>
          </callHandler>
        </policy>
      </interception>
    </container>
  </unity> 

  don't forget to add the section definition into configSections:

    <section name="unity" type="Microsoft.Practices.Unity.Configuration.UnityConfigurationSection, Microsoft.Practices.Unity.Configuration"/> 

This is doing the same as our fluent configuration - now you can see the named call handler constructor arguments being passed to the LogCallHandler which is applied as part of the "logging" policy with an assembly matching rule. We can then amend the Enterprise Library logging config to allow capture of parameters.

Now we can simply change the config file to remove the logging policy totally, or introduce more specific matchingRules to target the area of the code base that we haven't logged properly yet!