Introduction
Once upon a time, when there were no debuggers in the world and software was mostly console-based, programmers used to output tracing messages using printf()
statements. Today's world has seen huge advancement in technology, and printf()
has been replaced with Console.WriteLine()
.
We've all written code similar to the following:
static void Main()
{
Console.WriteLine("SuperApp started.");
DoSomething();
Console.WriteLine("SuperApp finished.");
}
Console.WriteLine()
statements in the above example are called "tracing statements" because they are only used to report our application's control flow, and have no other function. The output of Console.WriteLine()
is called the program trace. In this example, the tracing statements produce output that tells us if the DoSomething()
method has finished execution or not.
After giving the application some testing, we tend to remove the tracing code in order to improve performance (tracing can take a lot of time). Tracing instructions are usually commented out so that they can be re-enabled in the future. Unfortunately, this requires our program to be recompiled.
Some time later, after removing hundreds of comments and putting them back for the nth time, we get the feeling that our tracing solution is not perfect and we could benefit from:
- the ability to control the level of detail of our trace messages (such as displaying only warnings and errors or very detailed program trace),
- the possibility of turning the tracing on and off for components of our program separately, without turning the application off and recompiling it,
- writing trace messages to the file, system log, message queue, or other output,
- being able to send particularly important messages by email or store them in a database,
- and others...
It may seem that in the age of graphical debuggers, the usefulness of tracing-based solutions is limited. Sometimes, tracing turns out to be the only tool available, which can be used to locate bug in a mission-critical system that cannot be switched off for a single minute.
What is NLog?
NLog is a .NET library which enables you to add sophisticated tracing code to your application, delivering the functionality mentioned above and much, much more.
NLog lets you write rules which control the flow of diagnostic traces from their sources to targets, which could be:
- a file
- text console
- email message
- database
- another machine on the network (using TCP/UDP)
- MSMQ-based message queue
- Event Log
- and others, described here
In addition, each tracing message can be augmented with pieces of contextual information, which will be sent with it to the target. The contextual information can include:
- current date and time (in various formats)
- log level
- source name
- stack trace/information about the method that emitted the tracing message
- values of environment variables
- information about exceptions
- machine, process, and thread names
- and many more, as described here
Each tracing message is associated with a log level which describes its severity. NLog supports the following levels:
- Trace - Very detailed log messages, potentially of a high frequency and volume
- Debug -Less detailed and/or less frequent debugging messages
- Info - Informational messages
- Warn - Warnings which don't appear to the user of the application
- Error - Error messages
- Fatal - Fatal error messages. After a fatal error, the application usually terminates.
NLog is an open source library distributed at no cost under the terms of the BSD license, which permits commercial usage with almost no obligation. You can download the NLog binary and source code releases from its website. A graphical installer is also provided, which lets you install NLog in a preferred place, and enables integration with Visual Studio 2005 (Express editions are also supported), including:
- configuration file templates
- Intellisense for NLog config files
- code snippets
- Add Reference... dialog integration
Our first NLog-enabled application
Let's create our first application that uses NLog, using Visual Studio 2005. We'll start with a simple example that only logs to the console, and we'll be adding features that demonstrate how easy it is to control logging configuration in NLog.
The first step is to create a Visual Studio project (in this example, we'll be using C#), and to add an NLog configuration file using the "Add New Item..." dialog. Let's add an "Empty NLog Configuration File" and save it as "NLog.config":
Notice how a reference to the NLog.dll was automatically added to our project. The contents of the NLog.config file, which we'll be modifying in this tutorial, are:
="1.0" ="utf-8"
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" >
<targets>
</targets>
<rules>
</rules>
</nlog>
You only need to do one more thing: change the "Copy To Output Directory" option for this file to "Copy always". This way, our configuration file will be placed in the same directory as the *.exe file, and NLog will be able to pick it up without any special configuration.
It's time to configure the log output. In the <targets />
section, we'll add an entry that defines the console output and the required output layout:
<targets>
<target name="console" xsi:type="Console"
layout="${longdate}|${level}|${message}" />
</targets>
Notice how Visual Studio suggests the possible XML element names and attribute names/values. Once we type xsi:, we get a list of available log targets.
In the <rules />
section, we'll add a rule that routes all message whose level is Debug or higher, to the console. The XML is quite self-explanatory.
<rules>
<logger name="*" minlevel="Debug" writeTo="console" />
</rules>
In order to send a diagnostic message, we use a Logger
object, whose methods are named after supported log levels (Debug()
, Info()
, Fatal()
, and so on). Logger
objects can be created, thanks to the LogManager
class. It's recommended that logger names correspond to the full class names in the application. The LogManager
object has a GetCurrentClassLogger()
method that automatically creates a logger, based on the class it is being called from.
Let's modify the wizard-generated C# file by adding a "using NLog
" statement at the beginning, the code to create a logger, and an example log message. Note that you can quickly type the logger-creation statement by using the Code Snippet which is installed with NLog. Just type "nlogger" and press TAB twice.
using System;
using System.Collections.Generic;
using System.Text;
using NLog;
namespace NLogExample
{
class Program
{
private static Logger logger = LogManager.GetCurrentClassLogger();
static void Main(string[] args)
{
logger.Debug("Hello World!");
}
}
}
The result of running this program is a message written to the console which includes the current date, log level (Debug
), and the Hello World message.
Let's see how we achieved this:
LogManager.GetCurrentClassLogger();
creates an instance of the Logger
class which represents the source of the log messages which are associated with the current class.
- Calling the
Debug()
method on the source object sends the diagnostic message on the Debug level.
- Because our log level and source name match the rule defined in the
<rules />
section, the message gets formatted according to the "layout" specification and sent to the console.
A more advanced logging scenario
Let's record our log messages, along with some contextual information such as the the current stack trace, to both a file and the console. To do this, we need to define another target of type "File" and tell the <logger>
node that we want to write to it.
="1.0" ="utf-8"
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" >
<targets>
<target name="console" xsi:type="ColoredConsole"
layout="${date:format=HH\:mm\:ss}|${level}|${stacktrace}|${message}" />
<target name="file" xsi:type="File" fileName="${basedir}/file.txt"
layout="${stacktrace} ${message}" />
</targets>
<rules>
<logger name="*" minlevel="Trace" writeTo="console,file" />
</rules>
</nlog>
Here's the C# source code that emits some more log messages; additional methods are introduced here to observe the stack trace feature.
static void C()
{
logger.Info("Info CCC");
}
static void B()
{
logger.Trace("Trace BBB");
logger.Debug("Debug BBB");
logger.Info("Info BBB");
C();
logger.Warn("Warn BBB");
logger.Error("Error BBB");
logger.Fatal("Fatal BBB");
}
static void A()
{
logger.Trace("Trace AAA");
logger.Debug("Debug AAA");
logger.Info("Info AAA");
B();
logger.Warn("Warn AAA");
logger.Error("Error AAA");
logger.Fatal("Fatal AAA");
}
static void Main(string[] args)
{
logger.Trace("This is a Trace message");
logger.Debug("This is a Debug message");
logger.Info("This is an Info message");
A();
logger.Warn("This is a Warn message");
logger.Error("This is an Error message");
logger.Fatal("This is a Fatal error message");
}
When we run the program, the following information will be written to the "file.txt" in the application directory:
Program.Main This is a Trace message
Program.Main This is a Debug message
Program.Main This is an Info message
Program.Main => Program.A Trace AAA
Program.Main => Program.A Debug AAA
Program.Main => Program.A Info AAA
Program.Main => Program.A => Program.B Trace BBB
Program.Main => Program.A => Program.B Debug BBB
Program.Main => Program.A => Program.B Info BBB
Program.A => Program.B => Program.C Info CCC
Program.Main => Program.A => Program.B Warn BBB
Program.Main => Program.A => Program.B Error BBB
Program.Main => Program.A => Program.B Fatal BBB
Program.Main => Program.A Warn AAA
Program.Main => Program.A Error AAA
Program.Main => Program.A Fatal AAA
Program.Main This is a Warn message
Program.Main This is an Error message
Program.Main This is a Fatal error message
At the same time, we get this fancy colored output on the console:
Now, let's modify our configuration a bit. The typical requirement is to have a different level of detail depending on the output. For example, we only want messages whose level is Info
and higher written to the console, and we want all messages to be written to the file. With NLog, you only need to change the <rules />
section. No changes to the C# source code are necessary:
<rules>
<logger name="*" minlevel="Info" writeTo="console" />
<logger name="*" minlevel="Trace" writeTo="file" />
</rules>
After running the program, we find that Trace
and Debug
messages are only found in the file and aren't displayed on the console.
Logging configuration
It's now time to describe the NLog configuration mechanism. Unlike other tools, NLog attempts to automatically configure itself on startup, by looking for the configuration files in some standard places. The following locations will be searched when executing a standalone *.exe application:
- standard application configuration file (usually, applicationname.exe.config)
- applicationname.exe.nlog in the application's directory
- NLog.nlog in the application's directory
- NLog.dll.nlog in a directory where NLog.dll is located
- file name pointed by the
NLOG_GLOBAL_CONFIG_FILE
environment variable (if defined)
In the case of an ASP.NET application, the following files are searched:
- the standard web application file, web.config
- web.nlog located in the same directory as web.config
- NLog.nlog in the application's directory
- NLog.dll.nlog in a directory where NLog.dll is located
- file name pointed by the
NLOG_GLOBAL_CONFIG_FILE
environment variable (if defined)
The .NET Compact Framework doesn't recognize application configuration files (*.exe.config) nor environmental variables, so NLog only looks in these locations:
- applicationname.exe.nlog in the application's directory
- NLog.nlog in the application's directory
- NLog.dll.nlog in a directory where NLog.dll is located
Configuration file format
NLog supports two configuration file formats:
- configuration embedded within the standard *.exe.config or web.config file
- simplified configuration, stored in a separate file
In the first variant, we use a standard configSections
mechanism, which makes our file look like this:
="1.0" ="utf-8"
<configuration>
<configSections>
<section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog" />
</configSections>
<nlog>
</nlog>
</configuration>
The simplified format is the pure XML having the <nlog />
element as its root. The use of namespaces is optional, but it enables Intellisense in Visual Studio.
="1.0" ="utf-8"
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" >
</nlog>
Note that NLog config files are case-insensitive when not using namespaces, and are case-sensitive when you use them. Intellisense only works with case-sensitive configurations.
Configuration elements
You can use the following elements as children to <nlog />
. The first two elements from the list are required to be present in all NLog configuration files, the remaining ones are optional and can be useful in advanced scenarios.
<targets />
- defines log targets/outputs
<rules />
- defines log routing rules
<extensions />
- loads NLog extensions from the *.dll file
<include />
- includes the external configuration file
<variable />
- sets the value of a configuration variable
Targets
The <targets />
section defines log targets/outputs. Each target is represented by the <target />
element. There are two attributes required for each target:
name
- target name
type
- target type - such as "File
", "Database
", "Mail
". When using namespaces, this attribute is named xsi:type
.
In addition to these, targets usually accept other parameters, which influence the way diagnostic traces are written. Each target has a different set of parameters, they are described in detail on the project's homepage, and context-sensitive Intellisense is also available in Visual Studio.
For example - the "File
" target accepts the fileName
parameter which defines the output file name, and the Console
target has the error
parameter which determines whether the diagnostic traces are written to the standard error (stderr) instead of the standard output (stdout) of the process.
NLog provides many predefined targets. They are described on the project's homepage. It's actually very easy to create your own target - it requires about 15-20 lines of code and is described in the documentation.
Rules
Log routing rules are defined in the <rules />
section. It is a simple routing table, where we define the list of targets that should be written to for each combination of source/logger name and log level. Rules are processed starting with the first rule in the list. When a rule matches, log messages are directed to target(s) in that rule. If a rule is marked as final, rules beneath the current rule are not processed.
Each routing table entry is a <logger />
element, which accepts the following attributes:
name
- source/logger name (may include wildcard characters *)
minlevel
- minimal log level for this rule to match
maxlevel
- maximum log level for this rule to match
level
- single log level for this rule to match
levels
- comma separated list of log levels for this rule to match
writeTo
- comma separated list of targets that should be written to when this rule matches
final
- make this rule final. No further rules are processed when any final rule matches
Some examples:
<logger name="Name.Space.Class1" minlevel="Debug" writeTo="f1" />
- all messages from Class1
in Name.Space
whose level is Debug
or higher are written to the "f1
" target.
<logger name="Name.Space.Class1" levels="Debug,Error" writeTo="f1" />
- all messages from Class1
in Name.Space
whose level is either Debug
or Error
or higher are written to the "f1
" target.
<logger name="Name.Space.*" writeTo="f3,f4" />
- messages from any class in the Name.Space
namespace are written to both "f3
" and "f4
" targets regardless of their levels.
<logger name="Name.Space.*" minlevel="Debug" maxlevel="Error" final="true" />
- messages from any class in the Name.Space
namespace whose level is between Debug
and Error
(which makes it Debug
, Info
, Warn
, Error
) are rejected (as there's no writeTo
clause) and no further rules are processed for them (because of the final="true"
setting).
In the simplest cases, the entire logging configuration consists of a single <target />
and a single <logger />
rule that routes messages to this target depending on their level. As the application grows, adding more targets and rules is very simple.
Contextual information
One of NLog's strongest assets is the ability to use layouts. They include pieces of text surrounded by a pair of "${" (dollar sign + left curly brace) and "}" (right curly brace). The markup denotes "layout renderers" which can be used to insert pieces of contextual information into the text. Layouts can be used in many places. For example, they can control the format of information written on the screen or sent to a file, but also control the file names themselves. This is very powerful, which we'll see in a moment.
Let's assume that we want to augment each message written to the console with:
- current date and time
- name of the class and method that emitted the log message
- log level
- message text
This is very easy:
<target name="c" xsi:type="Console"
layout="${longdate} ${callsite} ${level} ${message}" />
We can make each message for each logger go to a separate file, as in the following example:
<target name="f" xsi:type="File" fileName="${logger}.txt" />
As you can see, the ${logger}
layout renderer was used in the fileName
attribute, which causes each log message to be written to the file whose name includes the logger name. The above example will create the following files:
- Name.Space.Class1.txt
- Name.Space.Class2.txt
- Name.Space.Class3.txt
- Other.Name.Space.Class1.txt
- Other.Name.Space.Class2.txt
- Other.Name.Space.Class3.txt
- ...
It's a frequent requirement to be able to keep log files for each day separate. This is trivial, too, thanks to the ${shortdate}
layout renderer:
<target name="f" xsi:type="File" filename="${shortdate}.txt" />
How about giving each employee their own log file? The ${windows-identity}
layout renderer will do the trick:
<target name="f" xsi:type="File"
filename="${windows-identity:domain=false}.txt" />
Thanks to this simple setting, NLog will create a set of files named after our employees' logins:
- Administrator.txt
- MaryManager.txt
- EdwardEmployee.txt
- ...
More complex cases are, of course, possible. The following sample demonstrates the way of creating a distinct log file for each person per day. Log files for each day are stored in a separate directory:
<target name="f" xsi:type="File"
filename="${shortdate}/${windows-identity:domain=false}.txt" />
This creates the following files:
- 2006-01-01/Administrator.txt
- 2006-01-01/MaryManager.txt
- 2006-01-01/EdwardEmployee.txt
- 2006-01-02/Administrator.txt
- 2006-01-02/MaryManager.txt
- 2006-01-02/EdwardEmployee.txt
- ...
NLog provides many predefined layout renderers. They are described on the website. It's very easy to create your own layout renderer. It just takes 15-20 lines of code, and is described in the documentation section of the project website.
Include files
It's sometimes desired to split the configuration file into many smaller ones. NLog provides an include file mechanism for that. To include an external file, you simply use the following code. It is worth noting that the fileName
attribute, just like most attributes in NLog config file(s), may include dynamic values using the familiar ${var}
notation, so it's possible to include different files based on environmental properties. The following configuration example demonstrates this, by loading the file whose name is derived from the name of the machine we're running on.
<nlog>
...
<include file="${basedir}/${machinename}.config" />
...
</nlog>
Variables let us write complex or repeatable expressions (such as file names) in a concise manner. To define a variable, we use the <variable name="var" value="xxx" />
syntax. Once defined, variables can be used as if they were layout renderers - by using the ${var}
syntax, as demonstrated in the following example:
<nlog>
<variable name="logDirectory" value="${basedir}/logs/${shortdate}" />
<targets>
<target name="file1" xsi:type="File" filename="${logDirectory}/file1.txt" />
<target name="file2" xsi:type="File" filename="${logDirectory}/file2.txt" />
</targets>
</nlog>
Automatic reconfiguration
The configuration file is read automatically at program startup. In a long running process (such as a Windows service or an ASP.NET application), it's sometimes desirable to temporarily increase the log level without stopping the application. NLog can monitor logging configuration files and re-read them each time they are modified. To enable this mechanism, you simply set <nlog autoReload="true" />
in your configuration file. Note that automatic reconfiguration supports include files, so each time one of the file includes is changed, the entire configuration gets reloaded.
Troubleshooting logging
Sometimes our application doesn't write anything to the log files, even though we have supposedly configured logging properly. There can be many reasons for logs not being written. The most common problem is permissions, usually in an ASP.NET process, where the aspnet_wp.exe or the w3wp.exe process may not have write access to the directory where we want to store logs. NLog is designed to swallow run-time exceptions that may result from logging. The following settings can change this behavior and/or redirect these messages.
<nlog throwExceptions="true" />
- adding the throwExceptions
attribute in the config file causes NLog not to mask exceptions and pass them to the calling application instead. This attribute is useful at deployment time to quickly locate any problems. It's recommended to turn throwExceptions
to "false
" as soon as the application is properly configured to run, so that any accidental logging problems won't crash the application.
<nlog internalLogFile="file.txt" />
- adding internalLogFile
causes NLog to write its internal debugging messages to the specified file. This includes any exceptions that may be thrown during logging.
<nlog internalLogLevel="Trace|Debug|Info|Warn|Error|Fatal" />
- determines the internal log level. The higher the level, the less verbose the internal log output will be.
<nlog internalLogToConsole="false|true" />
- sends internal logging messages to the console.
<nlog internalLogToConsoleError="false|true" />
- sends internal logging messages to the console error output (stderr).
Asynchronous processing, wrappers, and compound targets
NLog provides wrappers and compound targets which modify other targets' behaviour, by adding features like:
- asynchronous processing (wrapped target runs in a separate thread)
- retry-on-error
- load balancing (round-robin targets)
- buffering
- filtering
- backup targets (failover)
- and others described on the website
To define a wrapper or compound target in the configuration file, simply nest a target
node within another target
node. You can even wrap a wrapper target. There are no limits on the depth. For example, to add asynchronous logging with retry-on-error functionality, add this to your configuration file:
<targets>
<target name="n" xsi:type="AsyncWrapper">
<target xsi:type="RetryingWrapper">
<target xsi:type="File" fileName="${file}.txt" />
</target>
</target>
</targets>
Because asynchronous processing is a common scenario, NLog supports a shorthand notation to enable it for all targets without the need to specify explicit wrappers. You simply set <targets async="true" />
, and all your targets will be wrapped with the AsyncWrapper
target.
Programmatic configuration
In certain cases, you may choose not to use a configuration file, but to configure NLog using the provided API. The full description of this feature is beyond the scope of this article, so let's just outline the steps necessary to make it work. To configure NLog in your code, you need to:
- Create a
LoggingConfiguration
object that will hold the configuration
- Create one or more targets (objects of classes inheriting from
Target
)
- Set the properties of the targets
- Define logging rules through
LoggingRule
objects and add them to the configuration's LoggingRules
- Activate the configuration by assigning the configuration object to
LogManager.Configuration
This sample demonstrates the programmatic creation of two targets: one is a colored console, and the other is a file and rules that send messages to them for messages whose level is Debug
or higher.
using NLog;
using NLog.Targets;
using NLog.Config;
using NLog.Win32.Targets;
class Example
{
static void Main(string[] args)
{
LoggingConfiguration config = new LoggingConfiguration();
ColoredConsoleTarget consoleTarget = new ColoredConsoleTarget();
config.AddTarget("console", consoleTarget);
FileTarget fileTarget = new FileTarget();
config.AddTarget("file", fileTarget);
consoleTarget.Layout = "${date:format=HH\\:MM\\:ss} ${logger} ${message}";
fileTarget.FileName = "${basedir}/file.txt";
fileTarget.Layout = "${message}";
LoggingRule rule1 = new LoggingRule("*", LogLevel.Debug, consoleTarget);
config.LoggingRules.Add(rule1);
LoggingRule rule2 = new LoggingRule("*", LogLevel.Debug, fileTarget);
config.LoggingRules.Add(rule2);
LogManager.Configuration = config;
Logger logger = LogManager.GetLogger("Example");
logger.Trace("trace log message");
logger.Debug("debug log message");
logger.Info("info log message");
logger.Warn("warn log message");
logger.Error("error log message");
logger.Fatal("fatal log message");
}
}
What else is possible with NLog?
NLog supports some more logging scenarios, which couldn't be fully described here. See the links below for more information:
More information
Additional information about NLog can be found in the project homepage. Developers are welcome to join the project. There's a mailing list available, to which you can subscribe.
History
- 2005-06-09
- 2006-02-20
- Updated to reflect the 0.95 release changes.
- 2006-06-27
- Updated to reflect the 1.0 release changes. For a full list of changes made in the 1.0 release, click here.