preface

Logging has always been part of our development and operations. When a Bug occurs in the system, Xshell is often used to connect to the server, locate the log file, and identify the source of the problem.

With the rapid development of the Internet, our system is getting bigger and bigger. The way we rely on visual analysis of log files to troubleshoot problems is starting to highlight some issues:

  • In a distributed cluster environment, the number of servers may reach hundreds or thousands. How can I locate the servers?
  • How to locate the context information of other services based on exception information in microservice architecture?
  • As log files grow larger, they may be unable to be opened directly on the server.
  • Text search is too slow, unable to multi-dimensional query, etc

Faced with these problems, we need centralized log management to collect, manage, and access logs on all server nodes in a unified manner.

Today, what we do is we use Elastic Stack to solve them.

What is an Elastic Stack?

For those of you who are a little unfamiliar with Elastic, its predecessor was ELK, and the Elastic Stack is the successor to the ELK Stack.

The Elastic Stack corresponds to four open source projects.

  • Beats

The Beats platform is a collection of single-purpose data collectors responsible for collecting various types of data. Such as files, system monitoring, Windows event logs, and so on.

  • Logstash

Logstash is a server-side data processing pipeline that collects and transforms data from multiple sources simultaneously. Yes, it can both collect data and transform it. Unstructured data is collected and formatted into friendly types through filters.

  • Elasticsearch

Elasticsearch is a jSON-based distributed search and analysis engine. At the heart of the Elastic Stack, it stores data centrally. Data can be saved to Elasticsearch by using Beats and Logstash conversion.

  • Kibana

Finally, you can use Kibana to visualize your own Elasticsearch data.

This example uses SpringBoot+Dubbo microservices architecture with Elastic Stack to integrate logging. The structure is as follows:

Note that reading this article requires an understanding of the basic concepts and installation of ELK components. This article does not cover the installation and basic configuration process, but focuses on how to integrate with the project to meet the above requirements.

Two, collection, conversion

1, FileBeat

In the SpringBoot project, we first configure Logback to locate the log files.

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
	<file>${user.dir}/logs/order.log</file>
	<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
	    <fileNamePattern>${user.dir}/logs/order.%d{yyyy-MM-dd}.log</fileNamePattern>
	    <maxHistory>7</maxHistory>
	</rollingPolicy>
	<encoder>
	    <pattern></pattern>
	</encoder>
</appender>
Copy the code

Filebeat provides a lightweight method for forwarding and summarizing logs and files.

So, we need to tell FileBeat where the log files are and where to forward the content.

As shown below, we configure FileBeat to read all log files in the usr/local/logs path.

- type: log
  # Change to true to enable this input configuration.
  enabled: true
  # Paths that should be crawled and fetched. Glob based paths.
  paths:
    - /usr/local/logs/*.log
Copy the code

FileBeat is then told to forward the collected data to Logstash.

#----------------------------- Logstash output --------------------------------
output.logstash:
  # The Logstash hosts
  hosts: ["192.168.159.128:5044"]
Copy the code

In addition, FileBeat collects file data and reads it line by line. But the files FileBeat collects can contain messages that span multiple lines of text.

For example, intentional line breaks in open source frameworks:

The 2019-10-29 20:36:04. 427 INFO org. Apache. Dubbo. Spring. The boot. Context. Event. WelcomeLogoApplicationListener: : Dubbo Spring Boot (v2.7.1) : https://github.com/apache/incubator-dubbo-spring-boot-project: : Dubbo (v2.7.1) : https://github.com/apache/incubator-dubbo :: Discuss group : [email protected]Copy the code

Or Java exception stack information:

The 2019-10-29 21:30:59. 849 INFO com. Viewscenes. Order. Controller. OrderController HTTP - nio - 8011 - exec - 2 began to obtain an array of content... java.lang.IndexOutOfBoundsException: Index: 3, Size: 0 at java.util.ArrayList.rangeCheck(ArrayList.java:657) at java.util.ArrayList.get(ArrayList.java:433)Copy the code

So, we also need to configure multiline to specify which lines are part of a single event.

Multiline. pattern Specifies the regular expression pattern to match.

Multiline. negate defines whether it is a negation mode.

How multiline.match combines matched rows into an event, set to after or before.

As far as this may sound, let’s look at a set of configurations:

# The regexp Pattern that has to be matched. The example pattern matches all lines starting with [
multiline.pattern: '^\<|^[[:space:]]|^[[:space:]]+(at|\.{3})\b|^java.'

# Defines if the pattern set under pattern should be negated or not. Default is false.
multiline.negate: false

# Match can be set to "after" or "before". It is used to define if lines should be append to a pattern
# that was (not) matched before or after or as long as a pattern is not matched based on negate.
# Note: After is the equivalent to previous and before is the equivalent to to next in Logstash
multiline.match: after
Copy the code

The above configuration file says that if the text content is < or space or space +at+ package path or Java. At the beginning, treat this line as a follow-up to the previous line, not as a new line.

The Java exception stack above matches this re. So, FileBeat will

java.lang.IndexOutOfBoundsException: Index: 3, Size: 0
	at java.util.ArrayList.rangeCheck(ArrayList.java:657)
	at java.util.ArrayList.get(ArrayList.java:433)
Copy the code

These contents are used to start fetching the contents of the array… Part of.

2, Logstash

In Logback, we print logs with log level, execution class path, thread name, and so on.

One important piece of information is, do we want to separate these criteria out for statistics or precise queries when viewing logs from ELK?

If so, you need a Logstash filter that parses individual events, identifies named fields to build structures, and transforms them into a common format.

In this case, it depends on the format in which we have configured the log output in the project.

For example, we are most familiar with the JSON format. Let’s start with the Logback configuration:

<pattern>
    {"log_time":"%d{yyyy-MM-dd HH:mm:ss.SSS}"."level":"%level"."logger":"%logger"."thread":"%thread"."msg":"%m"}
</pattern>
Copy the code

Yes, the Logstash filter also happens to have a JSON parsing plug-in. We can configure it like this:

input{ 
   stdin{}
}
filter{
   json {
      source= >"message"
   }
}
output {
  stdout {}
}
Copy the code

Such a configuration means formatting the data using a JSON parser. We enter a line like this:

{
    "log_time":"The 2019-10-29 21:45:12. 821"."level":"INFO"."logger":"com.viewscenes.order.controller.OrderController"."thread":"http-nio-8011-exec-1"."msg":"Order data received."
}
Copy the code

The Logstash will return the formatted content:

But a JSON parser is not very useful because the MSG field in the log we print might itself be in JSON data format.

Such as:

{
    "log_time":"The 2019-10-29 21:57:38. 008"."level":"INFO"."logger":"com.viewscenes.order.controller.OrderController"."thread":"http-nio-8011-exec-1"."msg":"Order data received.{"amount": 1000.0."commodityCode":"MK66923","count"5,"id": 1,"orderNo":"1001"}"
}
Copy the code

The JSON parser will report an error. So what to do?

Logstash has a rich library of plugins for filters, or you can write expressions to match them if you have faith in the regex.

As we configured in Logback, the format of our log content is already determined, whether it is JSON or some other format.

Therefore, I recommend another: Dissect.

Dissect filters are a split operation. Instead of a regular split operation that applies a delimiter to the entire string, this operation applies a set of delimiters to string values. Dissect does not use regular expressions and is very fast.

For example, the author here to | as a delimiter.

input{ 
   stdin{}
}
filter{  
   dissect {
      mapping => {
	  "message"= >"%{log_time}|%{level}|%{logger}|%{thread}|%{msg}"
     }
   }   
}
output {
  stdout {}
}
Copy the code

Then configure the log format in Logback like this:

<pattern>
    %d{yyyy-MM-dd HH:mm:ss.SSS}|%level|%logger|%thread|%m%n
</pattern>
Copy the code

Finally, the correct result can also be obtained:

At this point, data collection and format conversion have been completed. Of course, the above configuration is all console input and output.

Let’s look at a serious configuration that takes data from FileBeat, converts it to a format via Dissect, and outputs the data to ElasticSearch.

input {
  beats {
    port => 5044
  }
}
filter{
   dissect {
      mapping => {
        "message"= >"%{log_time}|%{level}|%{logger}|%{thread}|%{msg}"
     }
   }
   date{
      match => ["log_time"."yyyy-MM-dd HH:mm:ss.SSS"]
      target => "@timestamp"
   }
}
output {
  elasticsearch {
    hosts => ["192.168.216.128:9200"]
    index => "logs-%{+YYYY.MM.dd}"}}Copy the code

Unsurprisingly, we can view the logs in Kibana by opening a browser. For example, if we look at an entry with log level DEBUG:

3, tracking

Imagine that we send an order request on the front end. If the back-end system is a microservice architecture, it may be through an inventory system, a coupon system, an account system, an order system, and more. How do you trace the call link of this request?

1. MDC mechanism

First, take a look at the MDC mechanism.

Mdc-mapped Diagnostic Contexts, which are essentially mappings maintained by the logging framework. Where the application code provides key-value pairs, which can then be inserted into log messages by the logging framework.

In short, we use mdC.PUT (key,value), and Logback automatically prints the value in the log.

In SpringBoot, we can write a HandlerInterceptor that intercepts all requests to generate a traceId.

@component public class TraceIdInterceptor implements HandlerInterceptor {Snowflake Snowflake = new Snowflake(1,0); @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler){ MDC.put("traceId",snowflake.nextIdStr());
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView){
        MDC.remove("traceId");
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex){}
}
Copy the code

Then configure the traceId in Logback to appear in log messages.

<pattern>
    %d{yyyy-MM-dd HH:mm:ss.SSS}|%level|%logger|%thread|%X{traceId}|%m%n
</pattern>
Copy the code

2, Dubbo Filter

Another problem is how to make the traceId pass back and forth in the microservices architecture.

Those familiar with Dubbo might think of implicit arguments. Yes, that’s what we use for traceId delivery.

@Activate(group = {Constants.PROVIDER, Constants.CONSUMER}, order = 99) public class TraceIdFilter implements Filter { @Override public Result invoke(Invoker<? > invoker, Invocation invocation) throws RpcException { String tid = MDC.get("traceId");
        String rpcTid = RpcContext.getContext().getAttachment("traceId");

        boolean bind = false;
        if(tid ! = null) { RpcContext.getContext().setAttachment("traceId", tid);
        } else {
            if(rpcTid ! = null) { MDC.put("traceId",rpcTid);
                bind = true;
            }
        }
        try{
            return invoker.invoke(invocation);
        }finally {
            if (bind){
                MDC.remove("traceId"); }}}}Copy the code

This way, we can happily view all log information for a particular request. For example, the following logs are for the request, order service and inventory service systems.

Four,

This article describes the basic concepts of Elastic Stack. And through a SpringBoot+Dubbo project, demonstrate how to achieve centralized log management, tracking.

In fact, Kibana has more analytical and statistical capabilities. So its use is not limited to logging.

The Elastic Stack is also pretty good. The author has recorded over 1 million pieces of user data on a virtual machine. The index size is 1.1G, and the speed of query and statistics is not inferior.