Beats:使用 Elastic Stack 来记录 Java Apps 日志

在我先前的系列文章中,我们介绍了如何使用 Elastic Stack 来分析 Spring boot 的微服务日志。这些文章是:

细心的开发者可能已经看出来了,我们使用 Logstash 来分析我们的日志,把非结构化的日志转换为结构化化的日志。这在很多的场合中是非常有用的。但是在上面例子中的 Java 应用的输出有一个非常不好的地方,那就是输出的日志是一个非结构化的日志,需要有 Logstashingest pipeline 来帮助我们实现数据的结构化。这在很多的情况下非常低效。我们能否在生产日志的时候,就输出结构化的日志呢?

Java 是一种公认​​的面向对象的编程语言,它代表了跨平台软件开发,并有助于普及“一次编写,随处运行”(WORA)概念。 Java 在全球数十亿设备上运行,并支持各种重要软件,例如流行的 Android 操作系统和 Elasticsearch。在本教程中,我们将介绍如何使用 Elastic Stack 管理 Java 日志。

Java 应用程序与以任何其他语言运行的应用程序一样,需要提供对其操作的可见性,以便管理它们的人员可以识别问题并进行故障排除。这可以通过简单地记录诊断信息来完成,但是,由于这些应用程序的可观察性要求与其范围和规模成比例地增长,因此找到正确的信息可能既繁琐又耗时。

幸运的是,Elasticsearch(用Java编写)是存储和搜索大量非结构化数据的出色工具。在此博客文章中,我将说明如何从 Java 应用程序编写日志,如何将 Java 日志导入 Elasticsearch 以及如何使用 Kibana 查找所需的信息。

为了方便大家一起做实验,请先下载我的一个 Java Maven 项目:https://github.com/liu-xiao-guo/gs-maven。这是一个完整的 Java 应用,在里面已经配置好调试的所有文件。

 

Java 日志概述

有几种不同的库可用于编写 Java 日志,所有这些库都具有相似的功能。 在此示例中,我将使用流行的 Log4j2 库。 实际上,Elasticsearch 本身使用 Log4j2 作为其日志记录框架,因此你在 Elasticsearch 日志记录配置期间可能会遇到它。

Log4j2 入门

要使用 Log4j2,你首先需要将相关的依赖项添加到构建工具的配置文件中。 例如,如果你使用的是 Maven,则需要在 pom.xml 文件中添加以下内容:

<dependencies>
  <dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.13.3</version>
  </dependency>
  <dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.13.3</version>
  </dependency>
</dependencies>

有了这个,一个简单的程序(如下面的程序)就足以看到一些日志输出:

package hello;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;

import org.joda.time.LocalTime;

public class HelloWorld {
	private static final Logger logger = LogManager.getLogger(HelloWorld.class);
	
	public static void main(String[] args) {
		LocalTime currentTime = new LocalTime();
		System.out.println("The current local time is: " + currentTime);
		Greeter greeter = new Greeter();
		System.out.println(greeter.sayHello());
		
		logger.error("Application is running!");		
	}
}

在上面,我们使用 logger.error("Application is running!"); 来记录 Java 日志。它会在 console 中输出如下的日志:

12:30:58.656 [main] ERROR hello.HelloWorld - Application is running!

显然这个日志的输出并没有导向到一个文件中。我们需要对 log4j2 进行配置才可以让这个日志定向输出到一个文件,同时也是我们需要的 JSON 文件格式。

Log4j2 配置在 log4j2.xml 中定义。由于我们尚未配置任何内容,因此日志记录库使用的默认配置为:

  • 将输出写入控制台的 ConsoleAppender。Appender 用于将日志数据发送到不同的本地或远程目标,例如文件,数据库,套接字和消息代理。
  • 如上所示构造输出的 PatternLayout。layouts 用于将日志数据格式化为 JSON,HTML,XML 和其他格式的格式化字符串。这为日志使用者提供了最合适的格式。
  • 最小错误日志级别,定义为 log4j 中 Logger 的根级别。这意味着根本不会写入任何较低级别的日志(例如 info)。这就是为什么(仅出于说明目的)我们对确实应该是信息消息的内容使用了一定程度的错误。

请注意,Java 代码与上面的配置详细信息无关,因此更改这些详细信息不需要更改代码。我们需要更改这些设置,以实现在 Elasticsearch中集中日志的目标,并确保日志可以被更广泛的 Java 应用程序使用。

 

配置 Log4j2

创建一个名为 log4j2.xml 的文件,并将其放在类路径可以访问的位置。 在其中添加以下内容:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <File name="FileAppender" filename="/path_to_logs/myapp.log">
      <JSONLayout compact="true" eventEol="true">
          <KeyValuePair key="@timestamp" value="$${date:yyyy-MM-dd'T'HH:mm:ss.SSSZ}" />
      </JSONLayout>
    </File>
  </Appenders>
  <Loggers>
    <Root level="trace">
      <AppenderRef ref="FileAppender"/>
    </Root>
  </Loggers>
</Configuration>

此配置将 FileAppender 与J SONLayout 结合使用,以将 JSON 格式的输出写入到文件中,以获取级别跟踪及以上的日志。 它还包含一个 @timestamp 字段,这将帮助 Elasticsearch 确定时间序列数据的顺序。

你还需要使用构建工具将 Jackson Databind 软件包添加为依赖项,因为在运行时需要它。 使用 Maven,这意味着将以下内容添加到 pom.xml 中:

<dependency>
    <groupId>com.fasterxml.jackson.core</groupId>
    <artifactId>jackson-databind</artifactId>
    <version>2.11.1</version>
</dependency>

经过上面的改造过后,我们就可以直接运行 Java 应用,并在 /path_to_logs/myapp.log 中看到我们所需要的日志信息。

现在以我的例子为例。首先克隆项目: 

git clone https://github.com/liu-xiao-guo/gs-maven

然后进入该项目:

$ pwd
/Users/liuxg/java/gs-maven/complete
liuxg:complete liuxg$ ls
dependency-reduced-pom.xml mvnw.cmd                   target
log4j2.xml                 pom.xml
mvnw                       src
liuxg:complete liuxg$ mvn clean package

上面的命令将生成一个 jar 文件包:

log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <File name="FileAppender" filename="/Users/liuxg/data/java_logs/java_app.log">
      <JSONLayout compact="true" eventEol="true">
          <KeyValuePair key="@timestamp" value="$${date:yyyy-MM-dd'T'HH:mm:ss.SSSZ}" />
      </JSONLayout>
    </File>
  </Appenders>
  <Loggers>
    <Root level="trace">
      <AppenderRef ref="FileAppender"/>
    </Root>
  </Loggers>
</Configuration>

在上面,我定义了我的 filename 路径。请根据自己的情况创建合适的路径,并修改这个文件。我们可以通过如下的命令来进行运行:

java -jar -Dlog4j.configurationFile=/Users/liuxg/java/gs-maven/complete/log4j2.xml ./target/gs-maven-0.1.0.jar 

上面的命令显示:

The current local time is: 12:45:40.001
Hello world!

我们查看在 log4j2.xml 中定义的 log 路径:

在上面,我们看见了以 JSON 格式表达的日志信息。我们可以直接使用 Filebeat 来对这个数据进行导入。

 

导入日志到 Elasticsearch

将日志写入文件有很多好处。 该过程既快速又健壮,并且应用程序无需了解最终将最终用于日志的存储类型的任何信息。 Elasticsearch 提供了 Beats,可以帮助你从各种来源(包括文件)收集数据并将其可靠而有效地运送到 Elasticsearch。 一旦日志数据进 Elasticsearch,你就可以使用 Kibana 对其进行分析。

发送到 Elasticsearch 的日志数据需要解析,以便 Elasticsearch 可以正确构造它。 Elasticsearch 能够轻松处理 JSON 数据。 你可以为其他格式设置更复杂的解析。

我们在 filebeat 的安装目录下创建如下的文件:

filebeat_json.yml

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /Users/liuxg/data/java_logs/java_app.log
  json:
    keys_under_root: true
    overwrite_keys: true
    message_key: 'message'
 
processors:
  - decode_json_fields:
      fields: ['message']
      target: json
 
setup.template.enabled: false
setup.ilm.enabled: false
 
output.elasticsearch:
  hosts: ["localhost:9200"]
  index: "java_logs"
  bulk_max_size: 1000

请注意:你必须用你自己的路径替换上面的 paths。

我们使用如下的命令来把数据导入:

$ ls filebeat_json.yml 
filebeat_json.yml
 
$ ./filebeat -e -c ./filebeat_json.yml

在运行完上面的命令后,我们使用如下的命令来检查已经生产的索引 java_logs:

GET _cat/indices

上面的命令显示:

我们在上面看到新生成的 java_logs 索引。我们可以使用如下的命令来进行查看:

GET java_logs/_search

我们可以看到如下的文档:

{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 3,
      "relation" : "eq"
    },
    "max_score" : 1.0,
    "hits" : [
      {
        "_index" : "java_logs",
        "_type" : "_doc",
        "_id" : "lHU7P3UBwnhF9_ZDScdQ",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2020-10-19T05:00:50.022Z",
          "loggerName" : "hello.HelloWorld",
          "endOfBatch" : false,
          "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
          "level" : "ERROR",
          "instant" : {
            "nanoOfSecond" : 8000000,
            "epochSecond" : 1603080024
          },
          "threadPriority" : 5,
          "threadId" : 1,
          "host" : {
            "name" : "liuxg"
          },
          "message" : "Application is running!",
          "thread" : "main",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.5.0"
          },
          "log" : {
            "offset" : 0,
            "file" : {
              "path" : "/Users/liuxg/data/java_logs/java_app.log"
            }
          },
          "agent" : {
            "hostname" : "liuxg",
            "ephemeral_id" : "0ec0c4ad-00a1-4754-bd30-e753852d4425",
            "id" : "b04e426a-35f8-4dbe-8702-42542624a45d",
            "name" : "liuxg",
            "type" : "filebeat",
            "version" : "7.9.1"
          }
        }
      },
      {
        "_index" : "java_logs",
        "_type" : "_doc",
        "_id" : "lXU7P3UBwnhF9_ZDScdQ",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2020-10-19T05:00:50.023Z",
          "log" : {
            "offset" : 317,
            "file" : {
              "path" : "/Users/liuxg/data/java_logs/java_app.log"
            }
          },
          "instant" : {
            "nanoOfSecond" : 613000000,
            "epochSecond" : 1603080522
          },
          "level" : "ERROR",
          "ecs" : {
            "version" : "1.5.0"
          },
          "host" : {
            "name" : "liuxg"
          },
          "agent" : {
            "type" : "filebeat",
            "version" : "7.9.1",
            "hostname" : "liuxg",
            "ephemeral_id" : "0ec0c4ad-00a1-4754-bd30-e753852d4425",
            "id" : "b04e426a-35f8-4dbe-8702-42542624a45d",
            "name" : "liuxg"
          },
          "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
          "threadPriority" : 5,
          "thread" : "main",
          "message" : "Application is running!",
          "threadId" : 1,
          "input" : {
            "type" : "log"
          },
          "endOfBatch" : false,
          "loggerName" : "hello.HelloWorld"
        }
      },
      {
        "_index" : "java_logs",
        "_type" : "_doc",
        "_id" : "lnU7P3UBwnhF9_ZDScdQ",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2020-10-19T05:00:50.023Z",
          "host" : {
            "name" : "liuxg"
          },
          "endOfBatch" : false,
          "instant" : {
            "nanoOfSecond" : 18000000,
            "epochSecond" : 1603082740
          },
          "threadId" : 1,
          "threadPriority" : 5,
          "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
          "input" : {
            "type" : "log"
          },
          "agent" : {
            "id" : "b04e426a-35f8-4dbe-8702-42542624a45d",
            "name" : "liuxg",
            "type" : "filebeat",
            "version" : "7.9.1",
            "hostname" : "liuxg",
            "ephemeral_id" : "0ec0c4ad-00a1-4754-bd30-e753852d4425"
          },
          "loggerName" : "hello.HelloWorld",
          "thread" : "main",
          "level" : "ERROR",
          "ecs" : {
            "version" : "1.5.0"
          },
          "log" : {
            "offset" : 636,
            "file" : {
              "path" : "/Users/liuxg/data/java_logs/java_app.log"
            }
          },
          "message" : "Application is running!"
        }
      }
    ]
  }
}

至此,我们已经完成了对 Java 应用日志的写入。希望对大家有所帮助!