REST Web API logging using NLog

Goals

  • Centralized logging of execution of all controller actions
  • Logging into various destinations (file system, database...)
  • Log authorized userId into custom database field

Solution

We chose NLog logging platform for .NET. Because we need to log authorized userId into custom database field we have to add custom parameters to NLog so we make wrapper around NLog and make logging facade.

1.) Define logging facade

public interface ILogger
{
    void Debug(string message);
    void Trace(string message);
    void Info(string message);
    void Warn(string message);
    void Error(string message);
    void ErrorException(string message, Exception exception);
    void Fatal(string message);
    void Fatal(string message, Exception exception);
}

We set UserId in NLogLogger constructor. NLogger implements ILogger interface.

public NLogLogger(Type loggerType, int? userId)
{
    if (userId != null)
        MappedDiagnosticsContext.Set("user_id", userId.ToString());
    logger = LogManager.GetLogger(loggerType.FullName);
}

Note that GlobalDiagnosticsContext is truly global. It is a static object MappedDiagnosticsContext is thread local (it uses a thread static dictionary to store its values)

2.) We inherited class from ActionFilterAttribute and override OnActionExecuting(HttpActionContext actionContext) method

In this method we do all the logging and get UserId value. We set UserId in AuthorizationFilterAttribute (TokenAuthorize).

On controller we have two filters applied first is AuthorizationFilterAttribute where we authorize user and set UserId and second is ActionFilterAttribute where we log every action.

We have controller decorated with two filters

[TokenAuthorize, LoggingFilter]
public class PackageController : ApiController

Because in Asp .NET MVC pipeline Authorization filter is executed before Action filter everything is fine.

3.) Database structure

[Id] [int] IDENTITY(1,1) NOT NULL,
[TimeStamp] [datetime] NOT NULL,
[Level] [varchar](100) NOT NULL,
[Logger] [varchar](1000) NOT NULL,
[Message] [varchar](3600) NOT NULL,
[UserId] [int] NULL,
[Exception] [varchar](3600) NULL,
[StackTrace] [varchar](3600) NULL,

*UserId is optional column and foreign key.

4.) NLog settings

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" throwExceptions="true">
<variable name="logDirectory" value="${basedir}/Logs/${shortdate}" />
<variable name="stackTrace" value="${longdate} ${exception:format=ToString,StackTrace}${newline}" />
<targets>
  <target name="f1" xsi:type="File" fileName="${logDirectory}/${shortdate}.txt" layout="${longdate} ${mdc:function_name} ${logger}::${message}"/>
  <target name="database" type="Database" connectionString="Data Source=*.*.*.*;Initial Catalog=xxxx;user id=xxxx;password=xxxx;MultipleActiveResultSets=True; ">
    <commandText>
      insert into LogApi ([TimeStamp],[Level],Logger, [Message], UserId, Exception, StackTrace) values (@TimeStamp, @Level, @Logger, @Message, 
      case when len(@UserID) = 0 then null
      else @UserId
      end, 
      @Exception, @StackTrace);
    </commandText>
    <parameter name="@TimeStamp" layout="${date}"/>
    <parameter name="@Level" layout="${level}"/>
    <parameter name="@Logger" layout="${logger}"/>
    <parameter name="@Message" layout="${message}"/>
    <parameter name="@UserId" layout="${mdc:user_id}"/>
    <parameter name="@Exception" layout="${exception}"/>
    <parameter name="@StackTrace" layout="${stacktrace}"/>
    <dbProvider>System.Data.SqlClient</dbProvider>
  </target>
</targets>
<rules>
  <logger name="*" minLevel="Info" appendTo="database" />
  <logger name="*" minLevel="Info" writeTo="f1" />
</rules>

Problems

  • Optional database column value can be NULL

Because NLog uses StringBuilder to make parameter value even if a parameter isn't and is of NULL value it initializes a value as (parameter value).ToString() which is empty string.

<commandText>
insert into LogApi ([TimeStamp], [Level], Logger, [Message], UserId, Exception, StackTrace) 
values 
(@TimeStamp, @Level, @Logger, @Message, 
      case when len(@UserID) = 0 then null
      else @UserId
      end, 
      @Exception, @StackTrace);
</commandText>
  • Detect errors when logging into database

By default NLog does not throw exceptions. Especially when we try to log into database we want to know what is wrong if log entry is not inserted. We just set throwExceptions to true and NLog will raise the exception.

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