In any non-trivial project, especially when the application is split across several tiers, I find adding a few logging statements has a real benefit. I have used log4net in the last four enterprise-level projects I've worked on and it is a marked improvement on the standard System.Diagnostics.Trace and Debug classes.
log4Net is an open source logging tool that allows all aspects of logging to be modified by changing the config file, which can be done after the code has been built and is in production. This config file controls which messages are logged, the format of messages and where log messages are sent.
For example, once the application is in production you may decide to have certain messages, for example errors and warnings, emailed to the developer and system admin whilst all other informational messages are logged to a text file. (This is the approach I used for PartyHandbook so I get immediate notification when an exception is thrown or a warning generated). Setting this up is just a matter of adding a few lines to the config file and can be configured such that the application doesn't even need a restart. See http://logging.apache.org/log4net/release/config-examples.html#smtpappender for details of the email appender.
The logging facilities are also useful in tracking down specific bugs in the live system. Imagine you have a system performing complicated calculations and you've received a report that the resulting value is not as you'd expect. Assuming sufficient logging has been placed in the application, this would be as simple as turning on 'Debug' level log messages for the MyProduct.ServerServices.ComplicatedCalculationModule and we would see the calculation steps for the live system without having to recreate the data and start the debugger up.
It does take a bit of practice to get into the habit of adding log statements in the right places and in sufficient quantity to provide the required level of verbosity but they can prove very useful in diagnosing problems and also providing another level of documentation to the code.
The areas I tend to add logging statements are:
- In top-level exception handlers. E.g. in Global.asax Page_Error method or in a try catch block wrapped around the Application.Run statement in the static Main method of a windows application or service.
- In security authentication code to log failed login attempts
-
In session handling code to determine when web sessions or nhibernate sessions are started and stopped
-
To record configuration settings read in from the config file (e.g. the database connection string used)
-
To record things that happen across process boundaries. E.g. web service messages that are sent and received
-
User actions. E.g. when user runs a system command by selecting a menu option or clicking a toolbar button.
Several other open source tools such as nHibernate also uses log4net to record a whole host of useful information regarding database persistence (E.g. the SQL statements are being sent to the database) so they can be configured in a similar manner.
This is a 30 second guide to using log4net in a project.
XmlConfigurator.Configure();
private static readonly ILog m_Log = LogManager.GetLogger( typeof(MyClass) );
m_Log.Debug( "This is my log message" )
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<configSections>
<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" />
</configSections>
<log4net>
<appender name="FileAppender" type=" log4net.Appender.FileAppender">
<file value="MyApp.log" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level %logger {%identity} - %message%newline" />
</layout>
</appender>
<root>
<level value="ALL" />
<appender-ref ref="FileAppender" />
</root>
</log4net>
</configuration>
When you execute your application you will see a new file in the same directory as the executable called 'MyApp.log'. It will contain an entry similar to this:
2006-10-12 14:00:10,883 [18076] DEBUG MyNamespace.MyClass {} – This is my log message
The full manual is available at http://logging.apache.org/log4net/release/manual/introduction.html and there are many examples of different configuration options at http://logging.apache.org/log4net/release/manual/configuration.html
The recommendation is to create a static member variable containing the logger object for each class where you want to log output. The logger will be obtained using the LogManager.GetLogger(type) method passing in the class's type.
The easiest way to get up and running and initialise log4net is to call XmlConfigurator.Configure(). However, any changes made to the config file whilst the application is running won't be re-read. If this is desirable the log4net config file can be placed in a separate file and the ConfigureAndWatch() method can be used instead. http://logging.apache.org/log4net/release/faq.html#config-reload
The easiest way to add the log to a class is to use Resharper live templates. Create a template with the abbreviation 'log' and use the following for the template text:
private static readonly ILog m_Log = LogManager.GetLogger(typeof ($TYPE$));
$TYPE$ is a template variable that will get its value from the name of the class where the line of code will be placed.
Once setup, you can create a logger by typing log and pressing tab.