After launching our latest product Bum A Lift, I immediately started thinking of all the improvements and optimizations we can add to the site to improve the web site's functionality, present a better user experience and polish the product as much as possible. Without the neseccary data at hand its very difficult to extract the right information that will lead to optimizations and improvements and that is the reason why I decided to create a blog about this topic, Tracing

Tracing is one of the techniques used in software engineering for data logging. Alot of people underestimate the importance of tracing within their systems. Tracing should not be treated just as a debugging tool but also a means of extracting important information related to your algorithms and processing performances as a whole. When it comes to  web sites its common to use analytical tools to study the behaviour of users on the web site and what can be improved to attract more traffic to your web site such as Google Analytics, however in some of the more sophisticated systems where a fair ammount of internal processing is done, it is also important to analyze the performance of your 'Search algorithm' or your 'Booking Engine' or your 'Profile matchmaker' so that you can always improve on your code. 

While it is very easy to create your very own tracer/logger, unless you need specific functionalities or services from your logger I suggest you use one of the very good simple tools out there and not "re-invent the wheel". For our own Bum A Lift, I didn't need any specific logs or levels which could not be found in some of the better free logging platforms out there so I conducted quite a bit of research to check which logger suits my needs.

Basically I needed a logger which can:

  • Log at different levels
  • Allow me to turn on/off any of the levels at any given time
  • Allow me to log simple text messages
  • Thread safe
  • Log file rotation (just in case I need to split the log files in the future)
  • Allow me to log to different targets (File, Database, Windows event viewer)

There are plenty of good tracers out ther and after conducting some research and eperimenting with some of the loggers myself I found this table which compares some of the most poipular loggers out there by feature (source: http://www.dotnetlogging.com/comparison/):

Logging Table

As you can see from the table above, the two tracers which seem to feature most of the traits we're seeking are the Log4Net, NLog and SmartInspect. If you're willing to pay for a logger, a commercial one might make sense, but for most of the required purposes NLog and Log4Net can do the job. 

These two loggers are quite extendable and can be modified to suite most of our needs. After doing some research on both I decided to move forward with NLog, the main reason being is that Log4Net's latest update was in 2006 and it hasn't changed much since then. On the other hand NLog is being continously supported and the documentation provided with NLog is very comprehensive. 

 NLog

 NLog is a free simple to use logging platform for .Net. It is very flexible to work with and very managable. It is able to log to several targets and with its use of filters one can practically create any desired logs relatively easy. In some of the past blogs we discussed the 'Seperation of Concerns' concept, In this blog I'm going to show you how to set up NLog in ASP.NET MVC and how you can use the Seperation of Concerns principle to add more flexibility to your system and allow the possibility of changing the logging tool in the future with minimal changes.

Lets starts with an MVC 4 solution where we have different layers of architecture and we might need logging in all the layers. We'll first try to download the NLog nuget package in our solution then we define our logging targets and then define an interface for our loggers so that we make sure that all our basic calls and services are available from whichever logger we decide to use.

Logging Targets

In most of the cases logging to a text file is enough but when you need to extract particular information from your traces, you might also need to log to a database. This was one of the most important features I was seeking when I was looking for a logger. In order to set up a database log for NLog, we need to create the following table:
 

CREATE TABLE [dbo].[NLog_Error](
    [Id] [int] IDENTITY(1,1) NOT NULL,
    [time_stamp] [datetime] NOT NULL,
    [host] [nvarchar](max) NOT NULL,
    [type] [nvarchar](50) NOT NULL,
    [source] [nvarchar](50) NOT NULL,
    [message] [nvarchar](max) NOT NULL,
    [level] [nvarchar](50) NOT NULL,
    [logger] [nvarchar](50) NOT NULL,
    [stacktrace] [nvarchar](max) NOT NULL,
    [allxml] [ntext] NOT NULL,
 CONSTRAINT [PK_NLogError] PRIMARY KEY CLUSTERED
(
    [Id] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY] GO ALTER TABLE [dbo].[NLog_Error] ADD CONSTRAINT [DF_NLogError_time_stamp] DEFAULT (getdate()) FOR [time_stamp] GO

 

Creating the NLog Configuration file

We must create a file called NLog.config in the root directory of our website. This file will contain all the configurations for our logger including targets, levels ad filters. A sample NLog.config file would look something like this:

<?xml version="1.0" ?>
<nlog autoReload="true" throwExceptions="true" internalLogFile="${basedir}/App_Data/nlog.txt" internalLogLevel="Debug"
internalLogToConsole="true">
<targets> <!--Useful for debugging--> <target name="consolelog" type="ColoredConsole" layout="${date:format=HH\:mm\:ss}|${level}|${stacktrace}|${message}" />

<target name="filelog" type="File" fileName="${basedir}/App_Data/BumALift.log" layout="${date}: ${message}" />

<target name="databaselog" type="Database">
<dbProvider>sqlserver</dbProvider> <!-- database connection parameters --> <!-- alternatively you could provide a single 'connectionstring' parameter --> <connectionString>data source=(local)\SQLExpressR2x64;initial catalog=BumALiftTest;user id=xx;password=xx;</connectionString>
<commandText> insert into NLog_Error ([time_stamp],[level],[host],[type],[source],[logger], [message],[stacktrace],[allxml]) values(@time_stamp,@level,@host,@type,@source,@logger,@message,@stacktrace,@allxml); </commandText>
<parameter name="@time_stamp" layout="${utc_date}" /> <parameter name="@level" layout="${level}" /> <parameter name="@host" layout="${machinename}" /> <parameter name="@type" layout="${exception:format=type}" /> <parameter name="@source" layout="${callsite:className=true:fileName=false:includeSourcePath=false:methodName=false}" />
<parameter name="@logger" layout="${logger}" /> <parameter name="@message" layout="${message}" /> <parameter name="@stacktrace" layout="${exception:stacktrace}" /> <parameter name="@allxml" layout="${web_variables}" /> </target>
</targets>
<rules> <logger name="*" minlevel="Fatal" writeTo="eventlog" /> <logger name="*" minlevel="Info" writeTo="filelog" /> <logger name="*" minlevel="Error" writeTo="databaselog" /> </rules> </nlog>

 As you can see in the targets section, we're defining all the <targets> which we want to log while in the <rules> section we're defining the levels we wish to log and to which of the targets we have just defined. This configuration can be configured at any time so as to increase/decrease the logging as required.

 Logging Interface

In here we define the methods and signatures we would wish any of our loggers to implement. In our case we're going to take a simple interface and implement the basic methods:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Web;
namespace MySampleApp.Services.Logging { public interface ILogger { void Info(string message);
void Warn(string message);
void Debug(string message);
void Error(string message); void Error(string message, Exception x); void Error(Exception x);
void Fatal(string message); void Fatal(Exception x); } }

 We would then need to implement the actual NLogger class which would implement the ILogger interface as shown below:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Web;
using NLog;
namespace MySampleApp.Services.Logging.NLog { public class NLogLogger : ILogger { private Logger _logger;
public NLogLogger() { _logger = LogManager.GetCurrentClassLogger(); }
public void Info(string message) { _logger.Info(message); }
public void Warn(string message) { _logger.Warn(message); }
public void Debug(string message) { _logger.Debug(message); }
public void Error(string message) { _logger.Error(message); }
public void Error(Exception x) { Error(x.innerMessage()); }
public void Error(string message, Exception x) { _logger.ErrorException(message, x); }
public void Fatal(string message) { _logger.Fatal(message); }
public void Fatal(Exception x) { Fatal(x.innerMessage()); } } }

Initialize your Logger

In the Global.asax we would then need to initialize our logger as shown below:

NLogLogger logger = new NLogLogger();
logger.Info("We're on the Index page for Activities");

 Thats it! We've set up our NLog logger, of course we would then declare the implementation of the logger using our dependency injection framework as shown in our previous blogs and call our logger within our code as we desire. using the setup explained above we should have 3 separate logging targets:

  • Database (Error level)
  • File log (Info level)
  • Console (Error level)

 There is much more we can do with NLog such as scheduled backups (splitting files), thread logging or creating different filters to enhance the logged messages. For more information I urge you to continue reading from NLogs well mantained documentation which can be found here: http://nlog-project.org/

If you have any suggestions or comments or maybe you have created your own open source logger and would like to promote it, we would be more than happy to test it for you, give you optimization suggestions and promote it for you. I hope you enjoyed this blog and please keep in touch!

Thanks

Shaun