Earlier this week Scott Hanselman tweeted a link to the MS Live Labs Simple Logging Framework (SLF).  I thought I'd check it out and post some comparisons to log4net for posterity.  Note this isn't a performance comparison, just a look at how the frameworks are used.

Spoiler: There are some neat ideas in here.  Check out SLF if you're new to logging, but my guess is that you'll quickly outgrow its capabilities.  If you're already logging, I don't see any reason to switch from more mature frameworks anytime soon.

A Quick Comparison

SLF is remarkably similar to log4net in its design.  SLF uses the concepts of appenders (SLF calls them "logs"), loggers (SLF calls them "loggers" too), and logging levels just like log4net.  In fact, there was virtually no change when porting my "hello world" log4net example to the SLF:

using System;
using LiveLabs.Logging;
namespace SimpleLoggingFrameworkExample
{
    class Program
    {
        static void Main( string[] args )
        {
            Logger Log = new Logger( typeof( Program ) );
            Log.Level = LogLevel.Debug;            
            
            Log.Debug( "Hello World!" );  
            Log.Inform( "I'm a simple log4net tutorial." );  
            Log.Warn( "... better be careful ..." );  
            Log.Error( "ruh-roh: an error occurred" );  
            Log.Fatal( "OMG we're dooooooomed!" );
            
            Console.ReadLine();
        }
    }
}

The most annoying change (and the cause of a failed build) was the rename of log4net's ILog.Info method to SLF's Logger.Inform.  Seems silly to me to change that one method name when the rest of the interface is identical....

Simple Formatting Control

SLF defaults to outputting to the process STDERR stream at a log level of Inform.  Line 10 drops the log level to Debug so we can see all of the output, which is formatted rather heinously IMO:

2009-03-06T20:49:57|   |No Thread Name|SimpleLoggingFrameworkExample.Program|Hello World!
2009-03-06T20:49:57|   |No Thread Name|SimpleLoggingFrameworkExample.Program|I'm a simple log4net tutorial.
2009-03-06T20:49:57|   |No Thread Name|SimpleLoggingFrameworkExample.Program|...better be careful ...
2009-03-06T20:49:57|   |No Thread Name|SimpleLoggingFrameworkExample.Program|ruh-roh: an error occurred
2009-03-06T20:49:57|   |No Thread Name|SimpleLoggingFrameworkExample.Program|OMG we're dooooooomed! 

Fortunately SLF provides a straightforward way to alter the message format. Every log object has a MessageFormatter property that can be set to a delegate to format messages for the log. Adding a bit of code to the example:

            Log.Level = LogLevel.Debug;                        
            Log.MessageFormatter = ( msg, log, level ) => String.Format( "{0} [{1}]: {2}", log, level, msg );
            Log.Debug( "Hello World!" );  

SimpleLoggingFrameworkExample.Program [Debug]: Hello World!
SimpleLoggingFrameworkExample.Program [Inform]: I'm a simple log4net tutorial.
SimpleLoggingFrameworkExample.Program [Warn]: ... better be careful ...
SimpleLoggingFrameworkExample.Program [Error]: ruh-roh: an error occurred
SimpleLoggingFrameworkExample.Program [Fatal]: OMG we're dooooooomed! 

A similar callback exists to format exception objects.  It is certainly easier to achieve this level of formatting control in SLF than it is in log4net, where you have to define custom formatter objects and layout patterns in your configuration. 

Configuration

SLF doesn't require an explicit call to initialize it with a configuration the way log4net does.  As I've pointed out SLF defaults to logging to STDERR at an Inform logging level.

If you do want some control, SLF does offer a Settings class that provides programmatic access to configure defaults and specifics for any of the loggers you've created:

Settings.Default.DefaultLogLevel = LogLevel.Debug; 

However, your options are limited.  You can set a default log level and log for all logger objects, and you can register message and exception formatters.  One glaring omission from the configuration space is the ability to configure default message and exception formatters for all loggers.  Looks like you're stuck setting them individually for now.

Language Feature Support

Another area where SLF improves on log4net is in the use of newer C# language features (log4net is based on the 2.0 version of the language).  Every log method in SLF accepts a lamba expression as an argument:

Log.Debug( () => {
        IDictionary envs = Environment.GetEnvironmentVariables();
        return "Current Environment: " + String.Join( ";", 
            (
                from string k in envs.Keys
                select ( k + "=" + envs[ k ].ToString() )
            ).ToArray() 
        );
    }
);

This is an excellent way to isolate complex logging logic, and to avoid expensive calls to obtain log message formatting arguments when no logging will actually take place; e.g.:

Log.Debug( () => 
    String.Format( "Result: [{0}]", obj.AVeryExpensiveOperation() ) ); 

To achieve the same effect in log4net, you have to explicitly wrap the code in a check of current log level:

if( Log.IsDebugEnabled )
{
    Log.DebugFormat( "Result: [{0}]", obj.AVeryExpensiveOperation() );
}

Personally, I prefer the former.  

Appender Options

This is where log4net beats SLF into a pulp.  log4net ships with a cornucopia of appender options, including the console, files, the event log, the debugger, the .NET trace subsystem, MSMQ, remoting, network endpoints, and various databases.  SLF ships with basically the equivalent of the log4net ConsoleAppender, FileAppender, and RollingFileAppender.

In addition,  SLF offers no built-in decoupling of the log formatting from your logging code the way log4net does.  I've shown in this post how easily you can override the message or exception format on a SLF logger object in your code, but consider also that there is no way to change this message format without changing your code.  E.g., if you someday decide to move from text to an XML log, you have to touch your code.  The log4net formatting configuration can be isolated to the app.config, making it touchable while leaving your code alone.

Summary

To sum up, the major differences between log4net and SLF are:

• log4net offers far more appender options and configurability.
• log4net has a larger user-base and more maturity.
  
• SLF provides easier access to simple formatting options for messages and exceptions.
  
• SLF supports the latest language features, while log4net does not.
  

I'll be honest - I like some of the ideas I see in the SLF project, but I really can't figure out the impetus for a new project when a mature and open project already exists.  There is this blurb from the project home page on codeplex:

Existing logging libraries are either too feature-light or too complex. That means you might end up spending as much time debugging your logging code as you do your application code. Or you may not even know that your “log” to database is even working until it’s too late. 

Yes, SLF makes a few things easier, but on the whole log4net offers far more for features for the same effort.  And I can't say I've encountered these difficulties with log4net - I don't consider log4net complex (in comparison to, say, the MS Enterprise Logging Framework), but that's probably because I've been using log4net for years. So let's say for argument's sake that log4net is overly complex and difficult to use.  The question at the front of my mind is this:

Why start over when you can openly contribute to the log4net project and make it better?

There is nothing earth-shaking in SLF that I see mandating a new project effort.  And by not contributing to log4net and starting over, you're dismissing the features and maturity it has to offer.

[insert "MS hubris!  They don't 'get' the open source thing...."  comment here]

I'm wondering how many people actually take the time to read the legalese to which they bind themselves when they install new software.

So please take a moment to fill out this survey.  I'll post the results in few weeks.

In my last Automation Framework post I asked for some advice on managing state between commands.  I didn't get any public feedback on the blog, but an old college of mine named Jon Lester tinkered with the blogged examples and sent me some of his code.  The nut of his idea was to use extension methods on an accumulator object to separate the domain logic from the testing apparatus.  I liked his approach, it wasn't something that would have popped into my head; it also put a spotlight on a simple and elegant solution to my state sharing problem.

Before I dive into Jon's idea, take a look at how I'm currently sharing state between my command objects:

//...
UserAccount account = new UserAccount();
CompositeCommand cmd = new CompositeCommand(
    new LoadUserAccountCommand { UserName = userName, Account = account },
    new MakeDepositWithTicketCommand { Amount = depositAmount, Account = account }
);
bool result = cmd.Execute( context );
// ... 

This example represents a single task on the system under test - specifically making a deposit into a user account.  The task effort is distributed across the LoadUserAccountCommand and MakeDepositWithTicketCommand objects, which must share a common Account object in order to accomplish the ultimate goal.

As I described previously, I like this approach okay, especially compared to some of the alternatives I've tried.  I think it's simple enough to understand, but at the very least, it requires some explanation which is an API FAIL.  And although you can make it work for value and immutable types, it takes an ugly hack.

My college's solution was to isolate the shared states from the commands, and expose the units of work in a fluent interface wrapping the shared state.  I whittled down his approach into a lean and clean interface - here's an example of the end result:

// ...
Execute.Using( context )
    .ForPlayer( account )
    .Deposit( 500m );
// ... 

Same unit of work, but a lot less code and far easier to understand IMO.  

Implementation

The root of the fluency is implemented in the Execute class, which encapsulates a command context (which I describe here):

public class Execute 
{
    IContext context;
    private Execute( IContext ctx )
    {
        context = ctx;
    }
    
    public static Execute Using( IContext context )
    {
        Execute e = new Execute( context );
        return e;
    }
    public AccountCommands ForPlayer( Account account )
    {
        return new AccountCommands( user, Process );
    }
    
    public GameCommands ForGame( Game game )
    {
        return new GameCommands( game, Process );
    }
    
    bool Process( ICommand[] commands )
    {
        foreach( var command in commands )
        {
            if( ! command.Execute( context ) )
            {
                return false;
            }
        }
        return true;
    }
}

As you can see, the only inroad to this class is the Using method, which returns a new instance of the execute class initialized with the Command Context.  The various flavors of the For() method are used to capture the shared state for a set of commands.  They each return a object supporting a redundant, fluent interface of commands around the state.  For example, here is some of the AccountCommands class:

public class AccountCommands
{
    Func< bool, ICommand[] > processCommands;
    
    public AccountCommands( Account account, Func< bool, ICommand[] > callback )
    {
        processCommands = callback;
        this.Account = account;
        
        processCommands(
            Chain(
                new LoadUserAccountCommand { Account = Account },
                new CreateUserAccountCommand { Account = Account }
            )
        );
    }
    
    public Account Account { get; set; }
    
    public AccountCommands Deposit( decimal amount )
    {
        processCommands(
            new MakeDepositWithTicketCommand {
                Amount = amount,
                Account = account
            }
        );
        
        return this; 
    }
    
    public AccountCommands Withdraw( decimal amount )
    {
        processCommands(
            new MakeWithdrawalWithTicketCommand {
                Amount = amount,
                Account = account
            }
        );
        
        return this;
    }
    
    public AccountCommands SetProperties( Hashtable properties )
    {
        processCommands(
            Compose(
                new LoadAccountPropertiesCommand {
                    Account = account
                },
                new SetAccountPropertiesCommand {
                    Properties = properties,
                    Account = account
                }
            )
        );
        
        return this;
    }    
    
    // etc ...
    ICommand Chain( params ICommand[] commands)
    {
        return new ChainOfResponsibilityCommand(
            commands
        );
    }
    ICommand Compose( params ICommand[] commands )
    {
        return new CompositeCommand(
            commands
        );
    }
}

Items of note:

• The constructor accepts two arguments: an Account object that represents the state shared by every member of the class, and a Func<> delegate that accepts an array of command objects and returns a boolean;
• Each public method of the class represents a single task one can perform against an account;
• Every public method simply composes one or more Command objects, which are passed to the processCommand callback for actual processing.

Huge Bennies

It still needs some work, but there are many things I like about this approach.  The thing I like most is that the fluent interface hides the complexities of composing command objects with shared state to perform system tasks.  I get all the benefits of the command pattern with minimal hassle.

With a bit of refactoring, I can easily reuse the *Commands objects from this fluent interface to do things besides execute the task.  E.g., perhaps I want to build up a system scenario and persist it, something like this:

var commands = new List< ICommand >();
BuildUp.Into( commands )
    .ForEachAccount
    .Deposit( 500m )
    .SetImage( PlayerImages.Face, testBitmap )
    .SetProperties(
        new {
            Address = "12 Main St.";
            City = "Anywheretownvilleton"
            State = "Texhomasippi"
            Zip = "75023"
        }
    );
// now the commands variable contains the defined 
// command structure and can be re-used against new
// players in the future, persisted to disk, etc.

Another big benefit of this approach is that it gives me a stable binding point for PowerShell - and by that I mean that I can deeply integrate this automation framework with PowerShell, leveraging all of the built-in freebies with virtually no effort.  But that is another post...