log4net: .NET Logging Tool

I took a brief look at log4net quite some time ago and have to admit I didn’t look closely enough! log4net is a port of the highly successful java based log4j logging library and is very mature tool. It’s been at the back of my mind to have another look, and my current project provided the opportunity and impetus. Without wanting this to sound like hype, log4net really does provide a one-stop shop for all your logging, tracing and diagnostics in a simple to use package.

It’s very easy to use out of the box, and highly intuitive. It comes with just about every ‘appender’ you could want (an ‘appender’ is a kind of output sink, i.e. a target for your logging messages). You can define the layout of the log messages. It’s extensible, if you require some other type of appender. It comes with the source code. It has excellent documentation. It’s free! If that doesn’t sound like a great deal, well, there’s no satisfying some people!

I’m going to be using and recommending log4net for all new .NET projects I work on.

You can download log4net here. Even though log4net is fully extensible, it is highly likely that it will meet your logging needs straight out of the box.

The excellent documentation contains config-examples for the list of currently supported appenders:

Of these, probably the most commonly used are the:

The documentation and tutorials section provide examples of how to configure the various appenders (\examples\net\1.0\Tutorials\ConsoleApp\cs\src, for example).

[Note: OutputDebugString is also worth looking at; it’s a Win32 API call that’s been there since before .NET, and is a nice technique for connecting to live applications and capturing logging on the fly using a separate application to catch debugging messages]

Adding log4net to your VS2005 project

Download log4net from the official site here. Unzip it to create a log4net folder (with the version number appended) containing the binaries, documentation, examples and source code.

Add the log4net assembly to your project

It’s good practice to include third party assemblies under source control as part of a project. That way, performing a get latest on a new PC includes everything.

If your project does not already contain a source-controlled external libs folder for third party assemblies:

  1. Right click on project
  2. Select “Add -> New Folder”, call it “ThirdPartyDlls” or “libs” or whatever your in-house standards specify.

OK, now add log4net:

  1. Right click on your external libs folder, select “Add Existing Item…” and browse to where you unzipped log4net and choose the release version of log4net.dll (\bin\net\2.0\release\log4net.dll)
  2. Right click on References, select “Add Reference …” and browse to your libs folder and pick the log4net.dll you just added.

Configure log4net: Creating and Specifying the Log4Net Config File

Although it is possible to add your log4net configuration settings to your project’s app.config or web.config file, it is preferable to place them in a separate configuration file. Aside from the obvious benefit of maintainability, it has the added benefit that log4net can place a FileSystemWatcher object on your config file to monitor when it changes and update its settings dynamically.

To use a separate config file, add a file named Log4Net.config to your project and add the following attribute to your AssemblyInfo.cs file:

[assembly: log4net.Config.XmlConfigurator(ConfigFile = “Log4Net.config”, Watch = true)]

Note: for web applications, this assumes Log4Net.config resides in the web root. Ensure the log4net.config file is marked as “Copy To Output” -> “Copy Always” in Properties.

Here is an sample log4net config file with several appenders defined:

<?xml version="1.0" encoding="utf-8" ?>
 
<log4net>
  <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="..\\Logs\\CurrentLog" />
    <appendToFile value="true" />
 
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="10000" />
    <staticLogFileName value="true" />
    <!-- Alternatively, roll on date -->
    <!--  -->
    <!--  -->
    <filter type="log4net.Filter.LevelRangeFilter">
      <acceptOnMatch value="true" />
      <levelMin value="INFO" />
      <levelMax value="FATAL" />
    </filter>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%-5level %date [%thread] %-22.22c{1} - %m%n" />
    </layout>
  </appender>
 
  <appender name="LogFileAppender" type="log4net.Appender.FileAppender">
    <file value="log-file.txt" />
    <!-- Example using environment variables in params -->
    <!--  -->
    <appendToFile value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <header value="[Your Header text here]" />
      <footer value="[Your Footer text here]" />
      <conversionPattern value="%date [%thread] %-5level %logger [%ndc] 
                 <%property{auth}> - %message%newline" />
    </layout>
    <!-- Alternate layout using XML            
     -->
  </appender>
 
  <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
    </layout>
  </appender>
 
  <appender name="EventLogAppender" type="log4net.Appender.EventLogAppender" >
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %-5level %logger
                         [%property{NDC}] - %message%newline" />
    </layout>
  </appender>
 
  <!-- Set the default logging level and add the active appenders -->
  <root>
    <level value="DEBUG" />
    <appender-ref ref="LogFileAppender" />
    <appender-ref ref="ConsoleAppender" />
    <appender-ref ref="RollingFileAppender" />
  </root>
 
  <!-- Specify the level for specific categories (“namespace.class”)-->
  <logger name="ConsoleApp.LoggingExample">
    <level value="ERROR" />
    <appender-ref ref="EventLogAppender" />
  </logger>
 
</log4net> 

In the “RollingFileAppender“ defined above, as Phil Haack points out: “Note that the file value (with backslashes escaped) points to ..\Logs\CurrentLog. [In Web Applications] this specifies that log4net will log to a file in a directory named Logs parallel to the webroot. You need to give the ASPNET user write permission to this directory, which is why it is generally a good idea to leave it out of the webroot. Not to mention the potential for an IIS misconfiguration that allows the average Joe to snoop through your logs.”

Using the Logger

At the start of each class declare a logger instance as follows:

public class ClassWithLoggingExample
{
    private static readonly ILog log = 

LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
 
    ...
}

You will need to add a “using log4net;” statement to each class file. By defining a logger in each class you have the ability to control the logging level on a class by class basis, simply by using the config file.

Once you have instantiated a logger, you can call its logging methods. Each method is named for the logging level. For example:

// In ascending order of severity (descending level of verbosity) 
log.Debug("This is a DEBUG level message. The most VERBOSE level.");
log.Info("Extended information, with higher importance than the Debug call");
log.Warn("An unexpected but recoverable situation occurred");
log.Error("An unexpected error occurred, an exception was thrown, or is about to be thrown", ex);
log.Fatal("Meltdown!", ex);

Whether or not a message shows up in your logs depends on how you have configured your appenders and the logging level you have set. If you want to avoid the overhead of string construction and a call to a logging method, you can first test to see if the appropriate level is active:

// If you are concerned about performance, test the appropriate
// log level enabled property (one for each of the log level methods)
if (log.IsInfoEnabled) 
    log.Info("Performance sensitive Info message");

The format of the logged output can be adjusted in the config file. See the log4net documentation that came in the zipped download (\doc\release\sdk\log4net.Layout.PatternLayout.html).

For web applications, add the following line to the Application_Error method in the Global.asax.cs file:

protected void Application_Error(object sender, EventArgs e)

{
    log.Fatal("An uncaught exception occurred", this.Server.GetLastError());
}

Contextual Logging

Log4net also has a mechanism called NDC (which stands for Nested Dynamic Context) where you can add contextual information to the log, allowing you to mark log entries as coming from a certain user or having a specific context. These can be nested in a push/pop stack fashion. For example:

// Push a message on to the Nested Diagnostic Context stack
using(log4net.NDC.Push(this.User.Name))
{
    log.Debug("log entry will be tagged with the current user's name");
}
// The NDC message is popped off the stack at the end of the using {} block

The context is added to log messages where the pattern layout contains “[%ndc]”.

Resources / References

If you run into permissions problems configuring logging for ASP.NET, check out Phil Haack’s post on configuring log4net for Web Applications here. His quick and dirty guide is also worth reading.

There is also a very useful log4net dashboard / viewer tool called l4ndash.

Bill Ryan has a blog post about The connection string for ADONetAppenders as well as his original post on a log4net walkthrough.

Free e-book: Basics of Compiler Design

Those long winter evenings will soon be with us here in Perth Australia, so what could be better than curling up with a nice thick, free e-book on the Basics of Compiler Design!

It might not be of interest to everyone(!), but if you do fancy a free e-book, Torben Mogensen has made his book available online as a PDF here.

If you’re interested in this kind of thing, check out Joe Duffy’s and Joel Pobar’s PDC session, Good For Nothing Compiler (PDC – TLN410)

Expresso 3.0 Beta, a Regular Expression Editor and Tester

I mentioned Expresso, a regular expression tool written by Jim Hollenhorst, on my blog back in February along with several other regular expression tools and resources. Version 3.0 is now in Beta and is well worth a look.

Expresso is not only a great tool for building and testing new regular expressions, but it’s also great for understanding existing expressions, as it provides an explained English breakdown of the various parts of an expression as a tree. It’s rapidly becoming my favorite regular expression tool.

NUnit 2.4 Final Release (2.4.0.2)

Most of the time I use the version of NUnit that happens to be installed on my system, and I only infrequently check for updates. When I visited the home NUnit site today I noticed that the final version 2.4 of NUnit has been released. You can download it here (release notes). It was released over a month ago and includes several enhancements such as a new syntax and internal architecture for Asserts based on the constraints found in JMock and NMock.

Get Visual Studio 2005 Intellisense with Google Earth KML files

In fact, given a custom XSD schema definition file you can use this method to get Visual Studio 2005 intellisense with just about any XML based file, including NAnt and NAntContrib schemas (see here for a build task to generate the combined NAnt and NAntContrib schema).

1) Download kml21.xsd from http://code.google.com/apis/kml/schema/kml21.xsd and paste it into C:\Program Files\Microsoft Visual Studio 8\Xml\Schemas

2) Open regedit at HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\VisualStudio\8.0\Editors\{fa3cd31e-987b-443a-9b81-186104e8dac1}\Extensions and add a DWORD value of “kml” with value ‘2A’ (the value may vary depending on the editor). For other file extensions (such as .build) add the extension to the relevent editor at the \Editors\{GUID}\Extensions level.

3) In each .kml file, set the xml namespace to:

Updated: Jonathon Howey kindly pointed out that I missed the \Extensions part of the registry key, which I’ve now fixed. Thanks Jonathon.

Form Design and Label Placement

While James Avery was working on a side project he ended doing some research into form design and label placement, the results of which he blogged here, The Art of Label Placement in which he links to several interesting articles:

Web Application Form Design by Luke Wroblewski – This article covers the best ways to arrange labels and submission buttons.

Web Application Form Design Expanded by Luke Wroblewski – Another great article from Luke W. expanding on the same topics.

Label Placement in Forms by Matteo Penzo – Matteo takes Luke’s advice but applies eyetracking to evaluate how usable it is.

Our eyes and brain constantly ‘trick’ us into believing that much more of a scene is in sharp focus than actually is. In fact, the area of sharp focus, or fovea, is actually quite a small area of the total field of vision. Try it by staring ahead and checking things that are off centre.

In the last article, there is a marked difference in eye tracking times between the right aligned labels and the labels positioned directly above a control. When the labels are directly above the start of an input field, the label and start of field are obviously in focus at the same, greatly reducing eye movement, but how does this then relate to further cognitive processes? There is obviously a correspondence between saccade times (the time taken for the eye to center on an area of interest) and cognitive friction, but it is not clear whether it is in a strictly linear relationship.

“Eyetracking can show which parts of your user interfaces users see and which
parts seem to be invisible to them—not just by observing users and gathering
qualitative data, but also by analyzing their gaze plots and other quantitative
data.”: Introduction to Eyetracking: Seeing Through Your Users’ Eyes

There’s no denying that good layout and interaction design is essential for creating happy users. And strangely, I’ve never seen any articles from Microsoft on the topic of eye-tracking for testing usability? Now we are in the Age of User Experience I’m sure that will change!

Influential Software Development Blogs

Like many developers, I read several blogs every day. Not quite as many as I’d like, and certainly not as many as Robert Scoble, who by his own account reads 1000. This seems a tad high to me, as it works out to be 16+ hours a day if you spend just 1 minute at each blog (8.3 hours if you spend just 30 seconds reading each one).

Here are the ones I think have influenced me more than others (although it was a hard task to reduce this list from around seventy to just six). I’m sure many of you read these already:

Kathy Sierra: Kathy’s blog is insightful, entertaining and big on content and ideas. She is one of the visionarys behind O’Reilly’s Head First series of books. The focus is designing great software by creating passionate users. How do we do that? By writing software that really helps the user at each step of a task. The difference between good software and great software is the way it makes users feel. Empower them to be great and do a great job! Recently, she has stopped blogging, but I’m sure she will start again…

Scott Hanselman: Scott and his army of Hanselman clones(!) have covered just about every topic under the sun. Does he ever sleep? He covers pretty much everything including design, development and architecture. I’ve had more than one epiphany at Scott’s blog. His Hanselminutes webcasts are great. Go and grok him!

Jeff Atwood: Jeff has an easy, very enjoyable writing style. Jeff covers a diverse range of topics. Always food for thought and excellent, balanced observations. He never ceases to amaze with his originality and breadth of subject matter.

Scott Guthrie: For ASP.NET you can’t pass this blog by. Superb! Scott’s PDC presentations never fail to entertain and get his points across. His Tip/Tricks section is required reading for all ASP.NET developers. Scott is a program manager for so many areas of .NET, you be forgiven for assuming he’s also been cloned!

ArcCast hosted by Ron Jacobs, has a large number of podcasts and webcasts available, with an architectural flavour but also covers other topics such as usability. Great resource! I met Ron when we were lucky enough to have him present here in Perth, and he’s an amazing guy.

Joel Spolsky: not as active as it once was, but Joel’s archive is worth reading. Try reading his Unicode article…The first time I read it, I felt so dumb!… I have several of his collections of essays on software development in hard copy, but most of the material is free to read on his site.

These six blogs cover many of the important areas that developers are required to be familiar with. Who do you read?

C# Code Snippet: Ensure Filename is Unique

OK, this is not exactly going to be the most complicated C# code snippet you will ever see. I’ve often wondered why the .NET Framework does not include similar functionality to Explorer when copying and pasting files (if it does and I’ve somehow missed it, please post a comment and let me know!). I’ve often needed the simple logic of ensuring that saving a file to a specified folder does not clash with one of the same name. There are basically two ways of doing this: (1) simply modify the filename to include a string representation of a GUID (via Guid.NewGuid().ToString()), or (2) or modify the filename to prepend something like “Copy (?) of “ checking until the name is unique. Here is a minimalist implementation of the second:

/// 
/// See main overload.
/// 
/// a fully pathed filename
/// a unique fully pathed filename
public static string EnsureUniqueFilename(string fullFilePathname)
{
    string destFolder = Path.GetDirectoryName(fullFilePathname);
 
    if (String.IsNullOrEmpty(destFolder))
        throw new ArgumentException("You must pass a fully pathed filename");
 
    return EnsureUniqueFilename(fullFilePathname, destFolder);
}
 
/// 
/// Return a unique filename of the form, 'Copy of (?) OriginalFilename.ext'
/// NOTE: Does not adhere to the full semantics of the file explorer copy logic.
///       which creates first copy named as 'Copy of OriginalFilename.ext'
///       Nor does it rename any files. It simply returns a filename which is unique
///       It does not take into account multiple threads attempting to make use 
///       of the same filename.
/// 
/// a fully pathed filename
/// a destination folder
/// a unique fully pathed filename
public static string EnsureUniqueFilename(string fullFilePathname, string destFolder)
{
    string filename = Path.GetFileName(fullFilePathname);
    string renamedFile = Path.Combine(destFolder, Path.GetFileName(fullFilePathname));
 
    // Check if a file with same name exists in folder and try a modified name if neccessary...
    int intCopy = 0;
    while (File.Exists(renamedFile))
    {
        intCopy++;
        renamedFile = Path.Combine(destFolder, "Copy (" + intCopy.ToString() + ") of " + filename);
    }
 
    return renamedFile;
}