I have what I believe to be a fairly simple problem in theory, yet in reality it proves to be a bit more hairy.  Below I present the problem and the requirements as I see them as well as a few possible solutions.  The solution I've settled on may or may not be correct, so I'm tossing out here to see what you guys think.  By all means please post some feedback.

Problem

To have a common, consistent logging access across multiple assemblies (that I own) in an application.

Requirements

• I want to be able to have logging capabilities in any method of any class in my application.
• I want to define logging once and only once for my application. 
• I want to maintain testability by not having any unnecessary dependencies or unmockable objects. 
• I want as few assemblies to be aware of dependencies as possible.
• If at all possible I wanted to avoid having all of my classes have an external dependency on some interface (such as ILog)
  • I also want to avoid every class having a public property which exposes an ILog (for setter injection)

The Structure

To the right is a picture of the assembly dependency diagram.

Solution #1

I could use Windsor's logging facility as suggested by Casey Charlton except that the solution provided only seemingly works for my top level assembly, ABCCompany.MVC.Web.  I don't want my other assemblies to be aware that I'm using an IoC Container.  I especially don't want the assemblies to know I'm bound to a particular IoC container (in this case I'm using Castle's Windsor container).  I've emailed Casey about this and we are going to try to talk this through.  I'm interested to hear what his thoughts are given that on Castle's site it says about the logging facility (emphasis mine):

The logging facility provides a seamless way to add logging capabilities to your application. There are two levels of integration.

• Allow your classes to receive an ILogger instance for logging support
• Allow you to ask for an ILoggerFactory instance to provide logging support to classes that are not managed by Windsor.

While I wait to talk with Casey I have to discount this solution since I cannot see past the first assembly on how this would work and therefore cannot use this as my solution of choice.

Solution #2

This is what I've come up with so far.  Please comment if you see issues. 

I have set up a static class inside of the ABCCompany.Framework assembly from which all methods could call for Logging purposes.  This satisfies the requirements above which states that I do not want constructor dependencies nor public setters on all classes.  This solution however does mean that every assembly much also ship with the ABCCompany.Framework assembly and all of it's dependent assemblies.  I'm okay with this until I hear a reason that this is bad.  I view this much like when I do work with Castle that in order to get any behavior I have to bring Castle.Core along to the party.

I liked Casey's solution (Solution #1) except that I cannot see past it working in one and only one assembly.  I thought I could modify his solution by simply having a static class, which any assembly can reference and call.  By default the Logger would be set up with a NullLogger.  The Logging class would have a method available to change the underlying logger.  It would then be incumbent upon the application layer to change the logger if they actually wanted logging.  In my app this is the first thing that happens, the NullLogger is replaced by an actual logger by calling Log.SetLogger().

As you can see from the code below I've followed much of Casey's example.

               1:
              private
              static ILogger
logger;

               2:  

               3:
              public
              static ILogger
Logger

               4: {

               5: get

               6: {

               7:
              if (logger
== null)

               8: {

               9: logger
= NullLogger.Instance;

               10: }

               11:
              return logger;

               12: }

               13: }

               14:  

               15:
              public
              static
              void SetLogger(ILogger value)

               16: {

               17: logger
= value;

               18: }

I do have a dependency on the Castle.Core assembly (due to usage of types in Castle.Core.Logging).  However none of the classes using the Log static class have to reference anything to do with Castle since I've have methods which pass through to every method in ILogger (see example below):

               1:
              public
              static
              void Debug(string message)

               2: {

               3: Logger.Debug(message);

               4: }

               5:  

               6:
              public
              static
              void Debug(string message,
Exception exception)

               7: {

               8: Logger.Debug(message,exception);

               9: }

               10:  

               11:
              public
              static
              void Debug(string format, paramsobject[]
args)

               12: {

               13: Logger.Debug(format,
args);

               14: }

               15:  

               16:
              public
              static
              void DebugFormat(string format, paramsobject[]
args)

               17: {

               18: Logger.DebugFormat(format,
args);

               19: }

               20:  

               21:
              public
              static
              void DebugFormat(Exception
exception, string format, paramsobject[]
args)

               22: {

               23: Logger.DebugFormat(exception,format,
args);

               24: }

               25:  

               26:
              public
              static
              void DebugFormat(IFormatProvider
formatProvider, string format, paramsobject[]
args)

               27: {

               28: Logger.DebugFormat(formatProvider,
format, args);

               29: }

               30:  

               31:
              public
              static
              void DebugFormat(Exception
exception, IFormatProvider formatProvider, string format, paramsobject[]
args)

               32: {

               33: Logger.DebugFormat(exception,
formatProvider, format, args);

               34: }

The usage pattern becomes quite simple in that any class that references ABCCompany.Framework can use the ABCCompany.Framework.Logging.Log class.  No external references needs

The reason I chose to bind myself at the framework level to Castle's ILogger interface and not something like ILog (log4net) was because ILogger is an abstraction over the ILog interface.  Castle also provides some concrete implementations of ILogger, one of which is for log4net

• log4net (requires Castle.Services.Logging.Log4netIntegration.dll)
• NLog (requires Castle.Services.Logging.NLogIntegration.dll)
• ConsoleLogger
• DiagnosticsLogger
• StreamLogger
• WebLogger (TraceContext)
• NullLogger (used as placeholder)

As far as testing is concerned, the solution imposes no restrictions on testing.  In my testing assemblies my logging calls are swallowed by the null logger.  If I want to ensure the logger is called in my testing (interaction based tests), I can mock an instance of ILogger and call Log.SetLogger() and set up expectations on the mock ILogger.

As I've mulled over this solution now for about a day it feels pretty solid.  As I go through the requirements above they are all satisfied.  However I can only see as far as my current knowledge so I'm hoping that if you see issues with the above that you'll let me know.

I posted earlier this year with the basic question, Is Var Better?  I'm not the only one to question the reintroduction of var.  Rhys Campbell went as far as to say some abuse the new keyword. I will say that my initial aversion to using var has softened a bit.  However there are at least two issues I have with them.

1. Implicit conversions
2. Intellisense

Implicit Conversions

In my latest project I've encapsulated all domain knowledge in it's own assembly in DDD fashion.  We have the notion of a ProductSku, a unique identifier for a product.  A Product object therefore has a ProductSku property which identifies it.  I could have implemented the ProductSku property as a string type, but in thinking about my domain and remembering March is Not a Number ProductSku is now it's own first-class citizen type.

I have the following code to perform implicit conversion from a ProductSku to a string:

               1:
              ///
<summary>
            

               2:
              ///
Performs an implicit conversion from <see cref="JPCycles.Domain.ProductSKU"/>
to <see cref="System.String"/>.
            

               3:
              ///
</summary>
            

               4:
              ///
<param name="sku">The sku.</param>
            

               5:
              ///
<returns>The result of the conversion.</returns>
            

               6:
              public
              static
              implicit
              operator
              string(ProductSKU
sku)

               7: {

               8:
              return sku.value;

               9: }

In order to test this method I have the following code:

               1: [Test]

               2:
              public
              void Implicit_conversion_of_sku_to_string()

               3: {

               4:
              string skuValue
= "ZZ123456";

               5: var
sku = new ProductSKU(skuValue);

               6:  

               7: var
converted = sku;

               8:  

               9: Assert.That(converted,
Is.EqualTo(skuValue));

               10: }

As you can see in line 7, I'm using the var keyword.  The problem with this is that using var in the scenario keeps me from testing the code that I want to test.  The goal of the test is to confirm the implicit conversion of a ProductSku to string.  This happens in line 7.  However when using the var keyword, the compiler interprets the "converted" variable as a ProductSku object and not a string object, as I really want. 

See below for confirmation:

(You might be saying to yourself that the conversion still happens in line 9, when the ProductSku object is evaluated against a string.  You might be right?  Or...does the string get implicitly converted to a ProductSku object?  If you don't know the answer to that question off the top of you head you cannot rely on line 9 for your conversion.  Also you shouldn't be using your asserts to perform the work for which you are testing)

If I leave the var keyword in place in line seven, my test will pass and possibly deceive me into thinking I've properly tested my code.  Only when running a coverage report do I see that the implicit conversion method is never being called.

The use of var is fine, except that now I have to think about how the compiler will interpret a statement versus what I want in programming it.  The var keyword does the best it can, but sometimes that's not good enough.  As another example, compare the following code:

               1: IUser
user1 = new User();

               2: var
user2 = new User();

Intellisense

The use of var makes intellisense less effective.  It's not the compilers fault though.  Given the point where you use var, the compiler has no idea what you're going to type on the right-hand side of the expression, so it cannot help. 

Say, for example, I want to define a Dictionary<string,string> called "my list".  When I use the var keyword, I have to type out enough information from which intellisense can narrow down what I'm looking for.  I hear a lot from the proponents of var how great it is because complex declarations, especially with generics, can be avoided.  I disagree and only need to show you the example below to prove my point.  In the example below I'm writing the exact same line of code.  The first example uses var, the second does not, which would you prefer?

When using var I had to type everything since the compile cannot help me, only I had to type on the right hand side of the expression.  So I really have saved nothing.

Jeff Atwood posted that by not using var, you're being redundant.  I would say that by not being redundant, for which the compiler penalizes you nothing, you're being slower, because you cannot take advantage of build-in assistance, ie intellisense.

These two annoyances won't stop me from using var in various (read: limited) situations.  The point of this post is to caution the reader to not be too quick to jump on the var bandwagon.  In the first example it may cause you headaches in performing proper testing and in the second, it may slow you down with the loss of intellisense.

A coworker ran across the following and shared with me.

               1:
              Dim strpage

               2: strpage
= pageNumber.ToString()

               3:
              If Len(strpage)
= 1 Then

               4: strpage
= "000" & strpage

               5:
              ElseIf Len(strpage)
= 2 Then

               6: strpage
= "00" & strpage

               7:
              ElseIf Len(strpage)
= 3 Then

               8: strpage
= "0" & strpage

               9:
              End
              If
            

The programmer is trying to ensure that the page number, when printed out, is always four characters long.  This is not the best way to write this code.  I thought I'd keep this post to myself but unfortunately this isn't the first time I've seen code like this, it is quite common.

The better way to write the above is:

               1:
              Dim strpage

               2: strpage
= pagenumber.ToString("0000")

It's shorter, more concise, and easier to read.  Further the second example is more extensible.  If the requirements change to say the page number should be five characters, the first example must recompile.  The second example must be recompiled as well in it's current state, however the string "0000" could be moved to a configuration file somewhere and then wouldn't need to be.

About a month ago Jean-Paul Boodhoo announced a contest that he was sponsoring.  The contest idea centered around the idea of developing passion in others around you.  I have an immense amount of respect for JP having met him at ALT.NET Seattle.  When the contest was announced I thought I'd put in an entry as I enjoy the journey passion for my craft has taken me on with others.  Here is my entry in its entirety:

While I'm not quite sure that my entry will be legal - a bit on that in a second - I would still like to share my story.  As for the legality of my entry, the rules clearly state "Must be working full time as a software professional (not a student)" (emphasis mine).  While I ama full time software professional, I must say that I am, unequivocally, a student.  We all are, whether we realize it or not.  The one truth I keep encountering in my maturation as a developer is a bit of a paradox: the more I learn, the more I realize I don't know.  Therefore I approach software development as a student and view my coworkers as students as well.

When I started at my last place of employment I was humbled early and often by my lack of knowledge in areas I thought I knew well.  Rather than being deterred, it sparked a fire in me, and since then I've never turned back.  Being humble and realizing, for lack of better words, how stupid I was, was quite possibly the best thing for my maturation as a software professional.  That spark has matured into a passion that I can best describe as the feeling of a child on Christmas morning, eagerly shaking his sleeping brothers and sisters telling them that Santa has come.  It's the type of knowledge where you share it not to show how much smarter or better you are, but because you are, at your core, excited at the chance to share it with someone else.

Among things like reading blogs, starting a blog of my own, listening to podcasts, I started to teach more. There are a great many people who believe that the best way to learn is to teach others.  I fall squarely in that camp.  I began by timidly teaching a few of the weekly developer trainings that the company offered.  Soon, I was teaching quite regularly and in 2007, I taught more than anyone else in the company.  I focused many of my talks on areas where I struggled and on things I wanted to learn, realizing that if I struggled learning a concept/language/framework, others probably did as well.  In one training session I created an elaborate hands-on demonstration of how events and delegates work.  Participants were given a card stating what they should do when a specific event occurred.  It started innocently with me turning off the light switch and, at it's height, had people walking all over the room, some making marks on the white board, others moving objects around the room, and still others doing various assigned tasks.  I was told later by someone that, "...it was the best training of events and delegates they ever had seen."  That comment was special to me. 

Why do I think I deserve to win this contest?  Honestly, I don't know that I do.  I'm not an "alpha" type, I haven't produced tons of tutorials or webcasts to help the community, and most of you probably have never heard of me.  However, I believe that if you ask current and former coworkers, they would say that I seek to help and mentor others as well as offer myself up to be mentored.  To me, more than having a large internet following, I desire to impact those around me.  Below are two recent such examples.  The first is an email I received a bit after I left my last place of employment:

Hey Tim,

How are you and howz your new work? Hope you have settled down.

Here same as usual , I got to take your big desk J yeeeeee . Josh A is sitting at your place with my small desk.

Hey listen thanks for introducing Rhino mock , I am getting better at it and I like it ….

Usharani Kachegere

The second example is is from a younger developer, Toran Billups, who emailed me one day out of the blue when he saw that I updated my alumni page on our college website.  Toran emailed me innocently one day asking about my work experience.  We started chatting more and more and I provided whatever guidance I could to him.  I have enjoyed my time mentoring Toran, as it's been a bit more focused with one-on-one time.  I've gotten the chance to see him grow in his skill, and more importantly, his passion.  Below are some of his comments about his experience over the last year and a half in a recent chat:

"I think from the moment I 'emailed you' to ask for some 'mentor like advice' you have shown a true passion for software development/learning/etc."

"your words have pushed me to a level I only dreamed of 11 months ago"

"I'm knee deep in TDD and in part because of your words!"

"I just built a house - otherwise ... i would move just to work with you- honestly"

"it's like something happened after talking to you last year ... I never had anyone challenge me like you did"

"but again - without your 'patience' / 'care for others in the community' -- you could have brushed me off with a simple 'newb' comment instead - you took the time (out of your busy day) to help ask the 'right questions'

If you're reading this and you've found yourself losing passion for your craft, family, or faith, don't sit idly by.  Do something, anything, to get back into it.  Do what whatever it takes to reawaken your passion and foster that passion, you'll be much happier person for it.  I wrote last summer on my blog about passion in a post titled "Passion in Programmers", and I believe what I wrote in that post to be as true today as the day I wrote it.  In it I wrote, "Passion in my mind is a key characteristic of being a great developer.  A passionate developer will never stop learning and enjoys the journey of learning and thus is an asset to any team."

Compare the following two error messages and think about which you would find more helpful.  Then, the next time you are throwing exceptions with messages remember this post.

Error Message from Castle's Windsor IoC libraries:

Can't create component 'ProductService' as it has dependencies to be satisfied.

ProductService is waiting for the following dependencies:

Services:
- ABCCompany.Framework.Services.IInventoryService which was registered but is also waiting for dependencies.

ControllerInventory is waiting for the following dependencies:

Services:
- ABCCompany.Controller.IInventoryRequestInterpreter which was not registered.

Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.

Exception Details: Castle.MicroKernel.Handlers.HandlerException: Can't create component 'ProductService' as it has dependencies to be satisfied.

ProductService is waiting for the following dependencies:

Services:
- ABCCompany.Framework.Services.IInventoryService which was registered but is also waiting for dependencies.

ControllerInventory is waiting for the following dependencies:

Services:
- ABCCompany.Controller.IInventoryRequestInterpreter which was not registered.

Error Message from .NET framework:

Object reference not set to an instance of an object.

Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.
Exception Details: System.NullReferenceException: Object reference not set to an instance of an object.