top of page

Log Software Events and User Actions with NLog

Why logging?


Logging errors and other abnormal situations can be very helpful in identifying problems in your apps, especially when they're run by real users. For example, you can log exceptions, including their stack trace and the line number of the file where the exception occurred.


Error are not the only helpful things to log. You can also log events that happen in the software (also called tracing). This can help you understand what happened prior to an error occurring.


You can also log user actions, which are helpful for auditing purposes and statistics. For example, you can track who opened a patient or signed off on something. I've written about user logging in my blog post Keep Track of Your Users with a Usage Logger.


You can collect statistics about how often the software is used, which features, and by whom. This helps you understand how valuable the software and features are.


Logs are typically written to log files, but they may also be written to a database, or even sent to an e-mail address. Log messages can include important information about the user's environment, like the machine being used and the ID of the app's process.


In this blog post, I'll show you how to use and configure NLog so you can start logging errors and user actions in your apps.


Logging libraries


You can implement your own logging system, but there are several good libraries that can help you with this. And they're free!


You can always change your mind about which logging library you want to use. We'll design the code in such a way that you can easily change the specific library you want to use.


Most logging libraries handle output to files, databases, or even sending messages via e-mail. They're also highly configurable, giving you the flexibility to specify the message format and what information to include.


There are many logging libraries for the .NET Framework, but the two most common are log4net and NLog. The following articles reviews and compares various logging libraries:



The library log4net is one of the oldest ones. It's easy to use, but it's configuration is more complex than NLog. Also, it's not as actively developed as NLog.


I've been using NLog lately and I like how easy it is to configure and use. Their documentation is very good and includes many examples. For these reasons, I've chosen to show you how to configure and use NLog in this blog post.


Interface


To keep your software independent of the actual logging library, let's start by defining our own logging interface. We'll use this interface throughout our software, without directly referencing NLog.


It's common to use a different method for the different logging levels (that is, the severity of the log). The common levels are: Trace, Debug, Info, Warn, Error, and Fatal (see NLog - Log levels):


Level (Low to High)

Description

Trace

Very detailed information, such as when a method was entered or exited

Debug

Information that may be useful while debugging, such as intermediate calculations or values of variables

Info

Normal events, such as user actions or software behavior

Warn

Abnormal events, such as unexpected user input or actions, but the program should continue normally

Error

Typically exceptions that are handled in catch blocks, such as an invalid connection string, but the program may continue to run

Fatal

Major exceptions (possibly unhandled), such as running out of memory, that will likely cause the program to crash


Each method accepts a log message. It's also common to accept an exception object in case it's related to the message, such as when logging inside a catch block.


To start, add a new project to your solution (if your solution's name is MyApp, the project could be named MyApp.Logging). This project will simply contain the logging interface.


public interface ILogger
{
    void Trace(string message);
    void Trace(string message, Exception exception);

    void Debug(string message);
    void Debug(string message, Exception exception);

    void Info(string message);
    void Info(string message, Exception exception);

    void Warn(string message);
    void Warn(string message, Exception exception);

    void Error(string message);
    void Error(string message, Exception exception);

    void Fatal(string message);
    void Fatal(string message, Exception exception);
}

Implementation


The implementation will use NLog to make the interface methods work. We could change our library to log4net by creating a different implementation, preferably in a separate project.


Add a new project, perhaps named MyApp.Logging.NLog. Then add the NLog NuGet package (right-click on the project and select “Manage NuGet Packages…”, then search for “NLog”, and you should see the NLog package to install).


In the class implementation, we'll create an NLog logger instance in the constructor, and use it to implement the logging methods:


public class Logger : ILogger
{
    private readonly global::NLog.Logger _logger;

    public Logger(string name)
    {
        _logger = LogManager.GetLogger(name);
    }

    public void Trace(string message)
    {
        _logger.Trace(message);
    }

    public void Trace(string message, Exception exception)
    {
        _logger.Trace(exception, message);
    }

    public void Debug(string message)
    {
        _logger.Debug(message);
    }

    public void Debug(string message, Exception exception)
    {
        _logger.Debug(exception, message);
    }

    public void Info(string message)
    {
        _logger.Info(message);
    }

    public void Info(string message, Exception exception)
    {
        _logger.Info(exception, message);
    }

    public void Warn(string message)
    {
        _logger.Warn(message);
    }

    public void Warn(string message, Exception exception)
    {
        _logger.Warn(exception, message);
    }

    public void Error(string message)
    {
        _logger.Error(message);
    }

    public void Error(string message, Exception exception)
    {
        _logger.Error(exception, message);
    }

    public void Fatal(string message)
    {
        _logger.Fatal(message);
    }

    public void Fatal(string message, Exception exception)
    {
        _logger.Fatal(exception, message);
    }
}

The NLog logger requires a name for the logger since you can have more than one logger. We pass in the name from the Logger constructor. If we're going to use just one logger, we can give it a generic name like "Logger" (see example below).


The implementation is very simple, as it's just calling the NLog methods. Notice that our interface expects the message before the exception, whereas NLog expects the exception first. We could have mirrored NLog's convention, but I prefer to specify the message first.


Configuration


NLog can be configured in many ways. Typically, you'll want to specify the type of log—file, database, e-mail, etc. (see NLog - Targets)—and the layout of the log message (see NLog - Layout Renderers).


If you're using files, you could log everything into a single file. For multi-user apps, however, you may want to split up the logs into multiple files. For example, you could save the log files for a specific user in their own directory, where each log file represents a different run of the app. I'll show you an example of how to configure it this way.


For the log layout, you can include many things in any order. I like to include the following (in order): date and time, machine name, username, process ID, log level, log message, and exception message (if any).


The easiest and most flexible way to configure NLog is to use a configuration file (for the complete documentation, see NLog - Configuration file).


For stand-alone apps, you can add the NLog configuration to the app's App.config file. To do this, first add the "nlog" section in configSections, and then add the "nlog" element. Here's an example:


<configuration>
  <configSections>
    <section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog"/>
  </configSections>

  <!-- Logging -->
  <nlog
    xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    throwExceptions="false"
    >

    <variable name="logdir" value="C:\Path\To\Log\Directory" />

    <!--
    See https://github.com/nlog/nlog/wiki/Configuration-file
    for information on customizing logging rules and outputs.
     -->
    <targets>
      <target name="log" xsi:type="File" fileName="${var:logdir}/${windows-identity:domain=False}/${date:format=yyyy-MM-dd}_${processid}.log">
        <layout xsi:type="CsvLayout" delimiter="Tab" withHeader="false">
          <column layout="${longdate}" />
          <column layout="${machinename}" />
          <column layout="${windows-identity}" />
          <column layout="${processid}" />
          <column layout="${uppercase:${level}}" />
          <column layout="${message}" />
          <column layout="${exception:format=toString}" />
        </layout>
      </target>
    </targets>

    <rules>
      <logger name="*" minlevel="Debug" writeTo="log" />
    </rules>
  </nlog>
</configuration>

(I'm just showing you the relevant parts here, you may have more configuration elements.)


In this example, I first define the variable "logdir" to use later. This variable contains the path to the directory where the log files should be written to. You need to change this to your desired location.


Then, I specify the type of log (in this case, file) and the file path. For my specific app, the path of the log file starts with the "logdir" directory I specified earlier, then a directory named after the username, then a file name containing the date and the process ID.


This means that each user of my app will have a separate log directory. For example, if the user smithj starts the app today, the path to the log file will be


C:\Path\To\Log\Directory\smithj\2017-11-10_1234.log

I made up the process ID here, but in reality it is the unique ID of the currently running app. Since a user may open the same app multiple times, each session is logged in a different file.


The rest of the "targets" element specifies the layout for the log messages. I like to use a CSV (comma-separated values) file separated by tabs, which are easier to see with any text editor. Each line contains the date and time, machine name, username, process ID, log level, log message, and exception message (if any).


There are many other things you can include in your log messages, and I encourage you to browse the complete list at NLog - Layout Renderers.


In the "rules" element, I've specified that logs with a Debug level or above (Info, Warn, etc.) should be logged. In other words, logs with a Trace level will not be outputted. Which levels you want to output depends on the amount of logs you want to see. For example, very stable apps that have been tested thoroughly likely don't need Trace or Debug logs.


Example use of logging


As a simple example, lets log a successful log-in to the Eclipse application:


var logger = new Logger("Logger");

using (var app = Application.CreateApplication(null, null))
{
    var userId = app.CurrentUser.Id;
    logger.Info($"Logged in to Eclipse as {userId}");
}

This will write the following output using the configuration above:


2017-11-30 09:25:29.6009        CITRIX        DOMAIN\smithj        19272        INFO        Logged in to Eclipse as smithj

Of course, the machine name, domain, and username are all made up for this example.


For an exception, you could log it like this:


try
{
    var result = Calculate();
    logger.Debug("Calculation was successful");
    return result;
}
catch (Exception e)
{
    logger.Error("Calculation failed", e);
    throw;
}

The output would include the exception information (including the stack trace) at the end of the line. This can help you identify the problem that the user experienced.

Related Posts

See All

ESAPI Essentials 1.1 and 2.0

A few months ago, I introduced ESAPI Essentials—a toolkit for working with ESAPI (available via NuGet). I've recently added one major feature: asynchronous access to ESAPI for binary plugin scripts. Y

Announcement: ESAPI Subreddit

A few months ago, Matt Schmidt started the ESAPI subreddit. It's another useful resource for finding and discussing ESAPI-related topics. According to the description, This community is to post and di

Dump All Patient Data from ESAPI

If, for whatever reason, you need to dump out all of the data for a patient from ESAPI, there's a quick and dirty way to do it. Well, there are probably several ways to do it, but here's one I've foun

Kommentare


bottom of page