Code usually runs at different contextual levels. For instance, a job may run every minute to process a list of items and each item may have several operations associated with it. The job, items and processes would be the different levels. Are all of the log entries that could be logged at each of these levels of equal importance? Often not, until you need the one that you left out of course but if things are running as expected then just a log entry concerning the successful completion of the job might be enough. The idea here is to not create excess logging if things are running as expected so that you can quickly scan the logs to get a good feeling that things are working. Of course when things break you’re still going to want all of the other log entries to help you figure out what went wrong, just not all of the time.
The answer to this problem is the log level. When you choose to log a message from code you can assign it a level. The following are the commonly used levels defined in log4net in order of descending importance (note that there are others and you can even define your own).
- ERROR
- WARN
- INFO
- DEBUG
The following example shows log entries being written at these four log levels. There are also overloads and Format methods for each level for including exceptions and string formatting.
ILog logger = LogManager.GetLogger(typeof(LoggingClass));
logger.Error("Error message");
logger.Warn("Warn message");
logger.Info("Info message");
logger.Debug("Debug message");
I’ll generally use the levels in the following way:
- ERROR: only for unexpected exceptions. i.e. events that may indicate that the program state is incorrect.
- WARN: only for events that may indicate intervention is going to be required. i.e. queues are getting large or execution times are getting to unacceptable limits. Care is taken to ensure that large numbers of these aren’t streamed into the log.
- INFO: high level state changes. i.e. opening a TCP listening socket or a summary of processing events. Again, care is taken to ensure that large numbers of the these aren’t written to the log.
- DEBUG: everything else.
Once your code is written like this you can configure the output with a minimum level of importance so that only log entries at that level or greater will be included in the log.
This basic log4net XML configuration file will write all of your log entries to a file called log-file.txt in the same folder as your executable (note that under certain circumstances this isn’t always the case such as when your application is actually a Windows server in which case you’ll want to specify a fully qualified file name).
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
<appender name="FileAppender" type="log4net.Appender.FileAppender">
<file value="log-file.txt" />
<appendToFile value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %-5level %message%newline" />
</layout>
</appender>
<root>
<level value="ALL" />
<appender-ref ref="ConsoleAppender" />
</root>
</log4net>And you’d initialize log4net by using the following code as close to your application’s start-up as possible (assuming you’d stored the above XML in a file called log4netConfig.xml and put it into the same folder as your application’s executable).
log4net.Config.XmlConfigurator.Configure(new System.IO.FileInfo("log4netConfig.xml"));For more examples on configuring log4net check out their dedicated page: http://logging.apache.org/log4net/release/config-examples.html
I like production code to run at INFO level which would mean that you’d see in the log all log entries logged at levels INFO, WARN and ERROR. So think carefully about what you’d want to see when your application is working. You need to be able to look at a log and get a feel for whether things are working as expected so don’t want nothing but reams of logging would make it difficult to spot problems. Aim for having processing summaries and the rest can be enabled through configuration when you need it.