Error Logging Using Serilog, Elasticsearch 5, and Kibana 5

November 11, 2016 by Michael

Why Use Serilog Over NLog?

For the longest time I didn’t understand why everyone was so excited about Serilog.  I’ve used NLog for a long time and it seemed more than capable of doing what I needed:  logging error messages to some data store.

Then I stared using Elasticsearch.  Suddenly I saw the light.  Structured event data always struck me as one of those neat features that wasn’t really needed.  However, once you start using something like Elasticsearch the power of structured event data quickly become evident.

Adding the visualizations offered by Kibana takes your logging to the next level.  A quick glance at a dashboard and you instantly know if there has been an uptick in errors (or whatever you might be logging).  The interactive visualizations allow you to quickly filter out noise and identify the root cause of problems you or your users might be experiencing.

Installing the JDK

This part is frequently overlooked.  You need to have Java installed and running on the box you’re planning to use as your Elasticsearch server.  For the purposes of this tutorial I’m going to assume that you’re going to set things up on a Windows machine.  You’ll also need to ensure that the JAVA_HOME environment variable is correctly set.

Step 1: Download the JDK

You can download the current JDK from Oracle.  You’ll want to click on the “Java Platform (JDK) 8u111 / 8u112” link.  On the following page download the appropriate package (in my case it’s jdk-8u111-windows-x64.exe).  Once the download completes run the installer and let it do it’s thing.  In most cases the default options (install location, etc…) are just fine.

Step 2: Setting the JAVA_HOME Environment Variable

In order for Elasticsearch to work you’ll need to have the JAVA_HOME variable set.  In order to set the JAVA_HOME variable you’ll need to access the Advanced System Settings in Windows.  You can do that by:

  1. Click on the Start Menu
  2. Right click on Computer
  3. Select Properties
Accessing advanced system settings
Accessing the Advanced System Settings

In the window that appears, select Advanced System Settings in the upper left.  That will bring up a small dialog window with five tabs across the top:

  1. Select Advanced.
  2. Click on Environment Variables…
  3. In the System variables section click New…
  4. For the Variable Name use JAVA_HOME and for the value use the location of your install’s bin directory

Setting up Elasticsearch and Kibana

I’m not going to teach you the ins and outs of Elasticsearch.  I’m going to give you just enough information to get things up and running.  Elasticsearch is incredibly powerful and I strongly encourage you to get a book or consult with someone more knowledgeable than me.

Step 1: Download and Install Elasticsearch 

Elastic does a great job walking you through the steps necessary to setup Elasticsearch on any platform.  Rather than repeating that information here, I’ll simply point you in the right direction: https://www.elastic.co/downloads/elasticsearch.

Although the download page has some basic installation instructions, I found the instruction in the documentation to be much more helpful.  You can find that information here.

I would strongly recommend setting up Elasticsearch as a service.  However, you’ll want to make sure you have Elasticsearch successfully running before setting up the service.  It’s much easier to resolve problems when you can see the errors in the console window.

Step 2: Download and Install Kibana

Installing Kibana goes pretty much exactly like installing Elasticsearch.  Simply download the compressed file, decompress to wherever you like, then run the bat file.  You can download Kibana from here:  https://www.elastic.co/downloads/kibana.  You can find better installation documentation here.

If you want to setup Kibana to run as a service you can use the following command in the Windows Console or your preferred terminal (you can see my setup here):

sc create "ElasticSearch Kibana 4.0.1" binPath= "{path to batch file}" depend= "elasticsearch-service-x64"

That handy little line comes to you courtesy of Stack Overflow.

At this point you should be able to verify that Elasticsearch is running at http://localhost:9200 and that Kibana is running at http://localhost:5601 by visiting those URLs in your preferred browser.

Error Logging With Serilog

As mentioned in the introduction, we’ll be using Serilog instead of NLog.  This is so that we can take advantage of the structured data Serilog gives us in our Elasticsearch indexes.  Setting up Serilog with .NET Core is pretty straight forward.

Step 1: Add the Required Packages

Add the following packages to your project.json file:

{
  "dependencies": {
    "Microsoft.NETCore.App": {
      "version": "1.0.0",
      "type": "platform"
    },
    "Swashbuckle": "6.0.0-beta902",
    "Microsoft.ApplicationInsights.AspNetCore": "1.0.0",
    "Microsoft.AspNetCore.Mvc": "1.0.0",
    // removed for length
    "Microsoft.Extensions.Options.ConfigurationExtensions": "1.0.0",
    "Serilog": "2.3.0",
    "Serilog.Extensions.Logging": "1.3.1",
    "Serilog.Sinks.Literate": "2.0.0",
    "Serilog.Sinks.ElasticSearch": "4.1.1"
  },
  // truncated to save space
}

Save your project.json file and let Visual Studio restore the packages.

Step 2: Modify Your Startup.cs

You’ll need to modify your Startup.cs in two places: the constructor and in the Config method.  First we’ll look at the changes to the constructor:

ElasticsearchConfig esConfig = new ElasticsearchConfig();
Configuration.GetSection("Elasticsearch").Bind(esConfig);

LoggerConfiguration loggerConfig = new LoggerConfiguration()
	.Enrich.FromLogContext()
	.Enrich.WithProperty("Application","App Name")
	.WriteTo.LiterateConsole();

if(esConfig.Enabled)
{
	loggerConfig.WriteTo.Elasticsearch(new ElasticsearchSinkOptions(esConfig.Uri)
	{
		AutoRegisterTemplate = true,
		MinimumLogEventLevel = (LogEventLevel)esConfig.MinimumLogEventLevel,
		CustomFormatter = new ExceptionAsObjectJsonFormatter(renderMessage:true),
		IndexFormat = esConfig.IndexFormat
	});
}

Log.Logger = loggerConfig.CreateLogger();

Looking at the code you should notice that loading settings from my appsettings.json file.  If you need some help with that you read my previous post.

I’ve enriched my events in two ways.  First I’ve configured Serilog to use the LogContext.  For more information take a look at the Serilog documentation here.  The second enrichment simply puts the application name on every event generated by Serilog.

I always want Serilog to write to the console (at least while the application is being developed).  To accomplish that I’m using the LiterateConsole Sink.  If you want to know why I’m using the LiterateConsole over the ColoredConsole you can read more about it here.

Lastly, depending on the value in esConfig.Enabled I’m conditionally setting up the Elasticsearch sink.  You can find all the information about the various configuration options here.  Here is the short version:

  • AutoRegisterTemplate – Tells Serilog to automatically register a template for the indexes it creates using a template optimized for working with Serilog events.
  • MinimumLogEventLevel – Kind of straight forward.
  • CustomFormatter – In order to avoid deeply nested objects Serilog writes inner exceptions as an array of exceptions.  This can be problematic for visualizations and some queries.  You can change this behavior using the ExceptionAsJsonObjectFormatter.
  • IndexFormat – This is the pattern Serilog will use to generate the indexes it creates.  Typically it’s something like “api-logs-{0:yyyy.MM.dd}”.  If you do not provide a format Serilog will use it’s default value.

Finally, modify your Configure method:

public void Configure(
	IApplicationBuilder app, 
	IHostingEnvironment env, 
	ILoggerFactory loggerFactory,
	IApplicationLifetime appLifetime)
{
	loggerFactory.AddSerilog();

	app.UseMvc();
	app.UseSwagger();
	app.UseSwaggerUi();

	appLifetime.ApplicationStopped.Register(Log.CloseAndFlush);
}

That’s it.  Now you’re ready to start writing some events to Elasticsearch.

Step 3: Write some exceptions to Elasticsearch

You’ll need to use Serilog’s ILogger interface wherever you need to log an event.  I tend to use StructureMap as my IoC container instead of the default implementation Microsoft offers.  This means I need to register the interface in my StructureMap configuration:

_.For().Use(Log.Logger);

Once that is done, I can easily inject Serilog into any object created via the IoC container (i.e. my controllers).  Writing an event with structured data to Elasticsearch is as simple as making the following call in your code wherever appropriate:

_logger.Error(ex, "Failed to create object requested by {@staff}", _staff)

For more information about the features Serilog offers please refer to their documentation.  I encourage you to take advantage of source contexts whenever possible.  Having the SourceContext property in your event data makes filtering a lot easier.

Using Kibana to View Error Logs

It’s taken a while, but you’ve finally got Elasticsearch setup, Kibana installed and running, and your source code writing events to an Elasticsearch index.  Great… now it’s time to start seeing the effort pay off.

Step 1: Setup Your Index Pattern

If this is the first time you’ve run Kibana you will most likely be looking at the screen where Kibana asks you to tell it about your index pattern:

Error logging index pattern configuration in Kibana
Error logging index pattern configuration in Kibana

If you recall, back when we setup the Serilog Elasticsearch sink one of the properties we configured was the IndexFormat.  This is the value you’ll want to use here less the date format portion of the string.  If you used “api-logs-{0:yyyy.MM.dd}” for your IndexFormat, then the Index Pattern is “api-logs-“.

With the Index Pattern set you’ll want to head over to the Discover tab.

Step 2: Save a Simple Query

Before you can discover anything you’ll need to make sure you’ve logged at least a few events to Elasticsearch.  You’ll also want to make sure that they occurred within the time frame you’re currently viewing (look in the upper right corner of the Kibana window).  As long as you have some events stored in ES, clicking on Discover should display a window that looks something like this:

Error log searching with Kibana
Error log searching with Kibana

In order to create a visualization you’re going to need to save a search.  You can find the full Discover documentation here.  For the purposes of moving forward, we’ll save a simple search:

  1. In the Query bar type in: level:Error
  2. Click on the search button (magnifying glass)
  3. Click on Save in the upper right corner
  4. Give the search a slick name like All Errors
  5. Click Save

Step 3: Create a Simple Visualization

With the search saved it’s time to move over to the Visualize section of Kibana.

Error logging visualizations in Kibana
Visualizations in Kibana

There are several visualizations you can create.  In this example we’ll create a simple Vertical Bar Chart using a Date Histogram to group the errors by date and time.  Creating this visualization is pretty straight forward:

  1. Select the Vertical Bar Chart option from the list of visualizations
  2. On the right you can select All Errors from the list of saved searches
  3. In the next window select X-Axis
  4. Under Aggregation choose Date Histogram
  5. Leave all of the default settings
  6. Click on the run button (Looks like a play button)
  7. Click Save in the upper right

Step 4: Build your dashboard

With the visualization saved you can easily add it to your dashboard.  You can find a lot more information about building dashboards than I can find in the official Kibana documentation.


Leave a Reply

Your email address will not be published. Required fields are marked *