MiniProfiler + Log4Net

Introduction

Google Analytics and other tools could help you monitor your application in a generic way. But when you have a performance problem on production like this StackOverflow question, you'll want a custom solution accoustic to your situation.

If there have been a few users or clients who kept complaining about performance of your application, you'll need to monitor the system response time for these users in particular.

Here's the log file that web administrators would love to have:

Idea

MiniProfiler ensures Session isolation for all time recordings and states. Indeed, it creates a new instance of itself and store the instance in HttpContext.

Log4Net enables high speed logging by buffering and flush batch of messages to rolling file on local disk or remote database.

They could be configured to work together in your application.

Using the Code

First, you create a custom storage class for MiniProfiler. I call it Log4NetStorage. Then, configure MiniProfiler to use it.

MiniProfiler.Settings.Storage = new Log4NetStorage();

The custom storage forwards the profiler's state to a logger to log to disk or database:

public void Save(MiniProfiler profiler)
{
    if (profiler == null || Log4NetLogger == null) return;
    Log4NetLogger.Info(string.Format("User<{0}>: {1}", profiler.User, profiler));
}

Lastly, you need to initialize, start and stop profiler for each request:

protected void Application_Start()
{
    AreaRegistration.RegisterAllAreas();

    WebApiConfig.Register(GlobalConfiguration.Configuration);
    FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);
    RouteConfig.RegisterRoutes(RouteTable.Routes);
    BundleConfig.RegisterBundles(BundleTable.Bundles);
    AuthConfig.RegisterAuth();

    Profiler.Initialize();
}

/// <summary>
/// The event when the application acquires request state.
/// </summary>
/// <param name="sender">
/// The sender.
/// </param>
/// <param name="e">
/// The event argument..
/// </param>
protected void Application_AcquireRequestState(object sender, EventArgs e)
{
    Profiler.Start(HttpContext.Current);
}

/// <summary>
/// This function is called by ASP .NET at the end of every http request.
/// </summary>
/// <param name="sender">
/// The sender.
/// </param>
/// <param name="e">
/// The event argument.
/// </param>
protected void Application_EndRequest(object sender, EventArgs e)
{
    Profiler.Stop();
}

Finally, don't forget to specify the output folder in your web.config file for Log4Net.

<?xml version="1.0" encoding="utf-8"?>

<!--
  For more information on how to configure your ASP.NET application, please visit
  http://go.microsoft.com/fwlink/?LinkId=169433
  -->
<configuration>
  <configSections>    
    <section name="log4net" 
    type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>

  <log4net>
    <root>
      <level value="ALL" />
      <appender-ref ref="RollingLogFileAppender" />
    </root>
    <appender name="RollingLogFileAppender" 
    type="log4net.Appender.RollingFileAppender">
      <file value="
      C:\Codeplex\miniprofilerlog4net\MiniExample\Mvc4Application\App_Data\rolling.log" />
      <appendToFile value="true" />
      <rollingStyle value="Date" />
      <datePattern value="yyyyMMdd-HHmm" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] - %message%newline" />
      </layout>
    </appender>
  </log4net>

</configuration>

I made a working MiniExample on CodePlex for you to download and explore the code.

Happy hacking.

--------------------------------------------------------------------------------
Additional works are published on my blog http://believeblog.azurewebsites.net/.