MS or OSS? Integration v. Features

I have to make a decision about a testing framework for my little project. I can't put it off any longer, or I'll really regret it.

At least in this category there's no shortage of options.

• NUnit. Part of the xUnit family. Among them, they have very similar syntax and capabilities.
• MSTest. This has a similar syntax, and is really well integrated into Visual Studio

I know that the purists out there would insist the one with more features, or the open source one for ideological reasons.

The power of a well-integrated solution shouldn't be dismissed. There's real merit in being able to get things going with a minimum of fuss, at the cost of long-term flexibility.

In this case, it doesn't look like I'll have to worry about it. ReSharper apparently integrates NUnit nicely.

log4net and Spring.Net, once again

Here's the goo to configure log4net in your spring.net config, assuming a property of type ILog named "log". It will initialize it with a named logger for "Document".

<property name="log">
<object type="log4net.LogManager,log4net" method="GetLogger">
<constructor-arg value="Document">
</constructor-arg></object>
</property>

Not that much to it, after all.

Logging in Spring.NET with log4net, initialization

It didn't take long to run into a snag.

The docs I've found so far say to get your log thusly:

ILog log = LogManager.GetLogger( "Outermost" );

Being the lazy bastard that I am, I started copying that into various constructors. The thought occurred to me that I should be able to put all of this into the spring config, but then there's that whole "being the lazy bastard that I am".

It didn't take long to run into an unhelpful exception:

Cannot instantiate Type [FileCrawler.FileCrawlerEngine] using ctor [Void .ctor(System.String)] : 'Index (zero based) must be greater than or equal to zero and less than the size of the argument list.'

What had I changed? I hadn't been as aggressive committing as I should've been, so there were a lot of little changes to poke through.

In the constructor of FileCrawlerEngine, I used the log that I had just created:

log = LogManager.GetLogger( "FileCrawler" );
log.Trace( String.Format( "Initializing FileCrawler for basepath {0}" ) );

Removing the Trace from the constructor resolved it.

Hrm.

I switched everything over to use log4net, directly, and it all worked okay. Even with a few threads thrown in. It takes even less upfront work. Create the log4net section, and follow the log4net docs. Just make sure that somewhere in your initialization, you call the following:

log4net.Config.XmlConfigurator.Configure();

Then, use it in your code, thusly:

log = log4net.LogManager.GetLogger( "NdxDocument" );
log.Info( "Informative" );

Using it directly exposes a better API, and it works as expected. I haven't gotten any errors, but I'll bet they are clearer than the one thrown by Spring.NET. It seems like Common.Logging requires more work for less results - I think I'll be sticking with the direct use of log4net, now.

It should be possible to springify the log initialization. That'll have to be a digression for later - I still have a lot of logging retro-fitting to do.

UPDATE: I took one look at adding logging to the SolrSharp library, and decided that now was as good a time as any to add the logging config to spring. I ran into a similar problem - logging in the constructor failed. It had a better error message, though:

"Error creating object with name 'Document' defined in 'config [C:\\Users\\michael.THREETREES\\Documents\\Visual Studio 2008\\Projects\\Crawler\\FileCrawler\\bin\\Debug\\FileCrawler.vshost.exe.Config#spring/objects] line 1' : Initialization of object failed : Cannot instantiate Type [NdxCore.NdxDocument] using ctor [Void .ctor()] : 'Object reference not set to an instance of an object.'"

Okay, so the property doesn't get set until after construction. That makes sense, at least for my problem. Too bad the Spring.NET guys didn't find a way around this for Common.Logging (and that I'm too dumb to figure it out myself).

UPDATE 2: Spring.net will call a specified initialization method, so that you can use the objects which are initialized by the container.

Reading the manual is for the weak. So, I'm weak.

Logging in Spring.NET with log4net

Wherein real progress is made...

I've mentioned that Spring.NET is a large project, with more than just the IoC container that I was babbling about. It also has log4net built in. At first blush, this seemed like a good thing. Then I got to the documentation.

The docs say use log4net syntax....
But they are working on a Common Logging...
Which they got going in 2006...
Okay, at least there's a "Common.Logging.dll" in the spring folder...
Hmmm, well the example that guy gives doesn't help much, where's the better docs? The example uses an external file - what if I don't want to do that? Is that INLINE?
Another chunk of doc sends us to the Common Infrastructure Libraries for .NET site...
The sum of whose libraries is logging. Heh.
Hm. Okee dokee. Does Common.Logging.dll include log4net?

Only one way to find out, I guess...
Added it's section name (the example from up there, and the corresponding configSections entry, to the app.config...nuthin. I'd expect to see something from Spring, at least.
Changed the logging level to "DEBUG" for Spring...still nuthin.
Okay, maybe some code is in order. How do I initialize this? Do I use the log4net syntax?
Back to the...oh crap...*sigh*...documentation.

Aha! Totally different. Yea, I could've started here, huh? But I didn't.

There's a few different adapters supported, including NLog, and EntLib. BTW, Microsoft's Enterprise Library is pretty nice - it has a lot of the functionality of Spring/Spring.NET, but isn't as complete. If you like a lot of what I'm talking about, but want an MS alternative, that would be it.

In fact, it might be more correct to re-title this post as "Logging in Spring.NET with log4net".

Log4NetLoggerFactoryAdapter seems to be what I'm looking for...
There's a lot of references to calling XmlConfigurator.Configure(). Is this from Spring.net?
Apparently, in the common/logging/factoryAdapter node, the configType of INLINE means "do it like you were using log4net, only you need this whole other section, too".

In goes a log4net section, then.

BLAMMO! no worky.

{"Could not load file or assembly 'Common.Logging.Log4Net' or one of its dependencies. The system cannot find the file specified.":"Common.Logging.Log4Net"}

Okay, that ain't there. It's hiding in the spring.net distribution under lib\net\2.0, along with some other dlls I'll probably want some day. I need to get the source code and add it to the project, but this should do for now.

Added Common.Logging.Log4Net and log4net as references in the project, and that got rid of the errors, and I got a chunk of output. Cool.

To summarize (don't you wish I had already?):

Using INLINE in the app config tells Common Logging to call XmlConfigurator.Configure(), which is (apparently - I forget how to use it) log4net initializer. To get it all working, you have to create a "common" section, as well as a "log4net" section. If I understand the history of all this correctly, it was to simplify dealing with multiple versions of log4net, with the bonus of being able to plug in other logging providers.

I'm thinking it might be simpler just to use log4net directly. I don't anticipate having that particular problem. I'll try it out, first, though.

To get it to work:

Reference log4net, Common.Logging, and Common.Logging.Log4Net in your project.
Then update your app.config to look something like this:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<configSections>
<section name="solr" type="org.apache.solr.SolrSharp.Configuration.SolrConfigurationSection, SolrSharp" allowLocation="true" allowDefinition="Everywhere" />
<sectionGroup name="spring">
<section name="context" type="Spring.Context.Support.ContextHandler, Spring.Core"/>
<section name="objects" type="Spring.Context.Support.DefaultSectionHandler, Spring.Core" />
</sectionGroup>
<sectionGroup name="common">
<section name="logging" type="Common.Logging.ConfigurationSectionHandler, Common.Logging" />
</sectionGroup>
<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net"/>

</configSections>

<log4net>
<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
</layout>
</appender>

<!-- Set default logging level to DEBUG -->
<root>
<level value="DEBUG" />
<appender-ref ref="ConsoleAppender" />
</root>

<!-- Set logging for Spring to INFO.  Logger names in Spring correspond to the namespace -->
<logger name="Spring">
<level value="DEBUG" />
</logger>
</log4net>

<common>
<logging>
<factoryAdapter type="Common.Logging.Log4Net.Log4NetLoggerFactoryAdapter,Common.Logging.Log4Net">
<!-- choices are INLINE, FILE, FILE-WATCH, EXTERNAL-->
<!-- otherwise BasicConfigurer.Configure is used -->
<!-- log4net configuration file is specified with key configFile-->
<arg key="configType" value="INLINE" />
</factoryAdapter>
</logging>
</common>

<spring>

<context>
<resource uri="config://spring/objects"/>
</context>
<objects>
</objects>
</spring>


</configuration>

Great - it's logging all of Spring.net's stuff. How do developers use it? Easy, once you have the references.

using Common.Logging;
...
ILog log = LogManager.GetLogger( "somelog" );
log.Error( "this is not an error!" );

Too simple, once it's set up.

Getting going with log4net

All the previous posts were about things I've done (and not everything I've done - they'll make nice future filler). I'll be typing this one up as I go through the learning curve, so there should be more detail for you bit-heads out there.

I've used log4net, and variations thereof (there's a log4*, it seems). Logging facilities and levels are very configurable, and adaptable to almost any need.

For example (and you'll see this one everywhere):

<log4net>
<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
  </layout>
</appender>
<root>
  <level value="DEBUG" />
  <appender-ref ref="ConsoleAppender" />
</root>
<logger name="Spring">
  <level value="INFO" />
  <appender-ref ref="ConsoleAppender" />
</logger>
</log4net>

An "appender" is your output, the console in this case. You can get color console output, if you like (love it!). There's also files, rolling files, Event Log, database, SMTP, and more appenders.

Next is our "layout" - what do we want the log entries to look like? This uses the very flexible "PatternLayout", which lets you use "%whatever" to format the output.

Then you've got your "root" element. These are the default logger settings.

Next, we have named logger, "Spring". An application can use this log by name, and its output can be somewhere else entirely.

From the developer's standpoint, things look like this:

Logger.Info( "informative message");
Logger.Warn( "warning message" );
Logger.Error( "error message" );

They don't have to know where they're writing their messages, or whether or not they are writing their message at all. If everybody uses named loggers, then you, the poor IT guy who gets called when it all breaks down, don't have to waste your time waiting for a developer to wake up, too. Just crank up logging wherever it seems appropriate, and dig on in.

Even better, when it comes time to move it, the necessary changes are obvious.

I know that there a lot of shops out there that will claim to be doing this. Many of them are, if "including the library in the project" counts. If you're not seeing this level of granularity, question why, and insist on it. It doesn't have to be log4net, but it should be very configurable.

Back on topic...

O'Reilly provides a nice tutorial.
The real dirt can be found at log4net's home at the ASF.