1. Overview

In this post, I talk about how to log in a distributed environment like the one based on microservices, using the ELK stack and Spring Sleuth to generate the CorrelationId.

When you need to log some kind of information in your application you usually chose to store this in text files on the same machine hosting your application. In a typical Java environment, the main logging framework is represented by LOG4J.

This framework has the concept of Appender, that let you choose where to send log information i.e. Console, File, Socket etc.

But what happens if we have multiple applications, like microservices, deployed on different machines or docker containers?

We greatly have two major problems to address:

First one is: Where is my log stored?

In a non distributed log without any kind of configuration, you should log on different machines and then retrieve files from them.

Second problem: How I can follow my request across multiple logs?

In this case, you could use timestamp and some kind of information like session or other to rebuild the trace let by your call to the system. It is very very hard!

Let’s try to address both problems…

2. Centralizing log with ELK

2.1 ELK Stack overview

Elk components
Elk components

ELK Stack is a stack made up by three components: Elastic Search, Logstash and Kibana.

Elasticsearch is an open-source, RESTful, distributed search and analytics engine built on Apache Lucene. Since its release in 2010, Elasticsearch has quickly become the most popular search engine and is commonly used for log analytics, full-text search, security intelligence, business analytics, and operational intelligence use cases.

Logstash is an open source data collection engine with real-time pipelining capabilities. Logstash can dynamically unify data from disparate sources and normalize the data into destinations of your choice. Cleanse and democratize all your data for diverse advanced downstream analytics and visualization use cases.

Kibana is an open source data visualization plugin for Elasticsearch. It provides visualization capabilities on top of the content indexed on an Elasticsearch cluster. Users can create bar, line and scatter plots, or pie charts and maps on top of large volumes of data.

2.2 Setting up easily an ELK stack with docker-compose

Using this GIT repository as a starting point, you can find the compose file and all instructions that you need to build up in a short time your ELK stack based on config files for all three components.

For this post, I’ll show you how to set up only the entry point for the stack: Logstash.

You can find on same git repository the Logstash pipeline configuration.

#this is the input section where we say to logstash how to receive log message.
#In this case we are saying that input will be based on tcp protcol sent over port 5000
input {
   tcp {
     port => 5000
   }
}

#In this section we specify where to send output collected by logstash.
#In this case we are sending it to elasticsearch host on port 9200
output {
   elasticsearch {
      hosts => "elasticsearch:9200"
    }
}

Let’s see another example this time using Filebeat as input. This can be useful when using older versions of log4j or other log systems that don’t support socket appenders.

Communication between Filebeat and logstash
Communication between Filebeat and logstash

 

input {
  beats {
    port => 5000
  }
}


#In this section we are saying to logstash to filter and manipulate input for extracting different fields from the log message.
#This will provide you the capability to filter on elastic search, messages based on some kind of field.
#You can install a lot of plugins but one of most common is <a href="https://www.elastic.co/guide/en/logstash/current/plugins-filters-grok.html">GROK</a>.
#You can test GROK on this very usefoul site https://grokdebug.herokuapp.com/
#Suppose to use as Log4j conversion pattern %d{ISO8601} | %-5p | %-16t | %-32.32C %4L | %X{bundle.id} - %X{bundle.name} - %X{bundle.version} | %m%n
#A grok filter could be (?%{TIMESTAMP_ISO8601}) \| %{LOGLEVEL:loglevel} * \| %{NOTSPACE:thread} * \| (?[A-Za-z0-9$_.]+) * *%{NONNEGINT:line} \| (%{NOTSPACE:bundle.id})? - (%{NOTSPACE:bundle.name})? - (%{NOTSPACE:bundle.version})? \| %{GREEDYDATA:message}$"
#
filter {
  grok {
   match => {
     "message" => "(?%{TIMESTAMP_ISO8601}) \| %{LOGLEVEL:loglevel} * \| %{NOTSPACE:thread} * \| (?[A-Za-z0-9$_.]+) * *%{NONNEGINT:line} \| (%{NOTSPACE:bundle.id})? - (% 
      {NOTSPACE:bundle.name})? - (%{NOTSPACE:bundle.version})? \| %{GREEDYDATA:message}$"
   }
   overwrite => [ "message" ]
  }
}

output {
  elasticsearch {
    hosts => "elasticsearch:9200"
  }
}

ELK address with or without Filebeat will address the problem of centralizing log and make searches against it.

We still have the problem of how to link executions of various microservices to obtain just one single trace.

3. Correlation Id

To reach this objective we need to introduce the concept of Correlation Id. Correlation ID is made up of two parts: traceId and spanId.
The system generates a correlation ID when you are making the first microservice call and pass that same ID to downstream services.

CorrelationId generation
CorrelationId generation

Spring Cloud Sleuth leveraging on LOG4J MDC (Mapping Diagnostic Context) enables autogeneration of correlationId so this becomes transparent for users.

2018-09-03 15:31:29.189 INFO [sleuth-downstream-service,903c472a08e5cda0] COLLECTING CUSTOMER AND ADDRESS WITH ID 1 FROM UPSTREAM SERVICE
2018-09-03 15:31:29.193 INFO [sleuth-upstream-service,903c472a08e5cda0] GETTING CUSTOMER WITH ID 1
2018-09-03 15:31:29.198 INFO [sleuth-upstream-service,903c472a08e5cda0] GETTING ADDRESS FOR CUSTOMER WITH ID 1

 

4. Conclusions

In this post, I showed you how to distribute your logs on ELK and how to keep them connected using correlation ID. ELK has a lot of advanced features that you can go deep on but this wasn’t in the scope of the post. Let’s see you on next post. Subscribe here to stay tuned.

Leave a Reply

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