常用日志框架合并异常堆栈信息为一行

一线大码
673 阅读7分钟

这篇文章是我在 2021-07-30 发表在 CSDN 的，现在迁移到掘金。

1. 背景介绍

事情是这样的，最近在搞公司系统日志的统一收集，目前公司服务大多数部署在 K8S 集群，个别服务直接部署在物理机上，需求是要将所有服务的日志统一收集管理，采用的方案是 EFK，具体就是各个服务器上（包括 K8S 的各个 POD）使用 Fluent Bit 进行日志采集，统一格式化后发送到 Kafka 集群，然后通过 Fluentd 集群消费 Kafka 集群对应 Topic 的消息，再经过集中处理，存储到 ES 集群，最后通过 Kibana 进行日志数据的可视化查询和分析。

但是这个 Fluentd Bit 有个很大的问题，官方文档写的很垃圾，然后网上资料又比较少，日志统一收集有个很重要的事情就是需要把异常堆栈信息合并为一行进行收集，这样才能方便后面的日志分析，通过查阅资料，主要是官方文档，仅仅实现了物理机上服务日志的多行合并采集（还用的是老的配置方式，官方提供的新的配置方式并不好使），K8S 服务这边没有找到具体的多行日志收集方案（官方提供的配置并不好使），只能实现单行收集，无奈只能考虑将堆栈信息进行合并打印，这样也算实现了异常日志堆栈的完整采集了。

因为我们的大数据平台框架采用的是 Flink，而 Flink 内部默认使用的是 Log4j2 日志框架（How to use logging），所以我仅研究了 Log4j2 的配置项，Logback 只是做了翻译、搬运和测试。

2. Log4j2

参考地址：How to format stacktrace in log4j2?

2.1. 问题描述

默认情况下，Log4j2 在多行上打印堆栈信息，用换行符分隔。像下面这样：

java.lang.NullPointerException: error enovountered
    at ...
    at ...
    at ...

我希望我的堆栈信息在一行上，也就是说，分隔符使用|，而不是\n。

java.lang.NullPointerException: error enovountered at ... | at ... | at ...

2.2. 解决方法

正如 Log4j2 的 Pattern Layout 文档所提到的，%throwable转换键族实际上支持更改单个堆栈跟踪元素以及“cause”异常的分隔符。

给定如下模式：

[%threadName] %-5level %logger{36} - %message{nolookups}%xThrowable{separator(|)}%n

你会得到如下输出：

[main] ERROR my.cool.Application - Catching java.lang.RuntimeException: I'm wrapping the NPE|   at my.cool.Application.main(Application.java:24) [main/:?]|Caused by: java.lang.NullPointerException: This is a forced NPE| at java.util.Objects.requireNonNull(Objects.java:228) ~[?:1.8.0_121]|   at my.cool.Application.main(Application.java:21) ~[main/:?]

源码在这里：

在这里插入图片描述

2.3. 延伸阅读

通过上面我们知道在日志格式上添加{nolookups}%xThrowable{separator(|)}可以实现该需求，这里解释下这些配置的含义。

2.3.1. {nolookups}

nolookups 有下面三种形式：

  • m{nolookups}{ansi}
  • msg{nolookups}{ansi}
  • message{nolookups}{ansi}

输出应用程序提供的与日志记录事件关联的消息。

添加使用ANSI转义的{ansi}消息，内置的ANSI代码的默认语法是：

@|code(,code)* text|@

例如，要将消息“Hello”呈现为绿色，请使用：

@|green Hello|@

要将消息“Hello”渲染为粗体和红色，请使用：

@|bold,red Hello|@

你也可以用下面的语法在配置中定义自定义样式名：

%message{ansi}{StyleName=value(,value)*( StyleName=value(,value)*)*}%n

例如：

%message{ansi}{WarningStyle=red,bold KeyStyle=white ValueStyle=blue}%n

调用方式是这样的：

logger.info("@|KeyStyle {}|@ = @|ValueStyle {}|@", entry.getKey(), entry.getValue());

使用{nolookups}记录如${date:YYYY-MM-dd}的消息不会使用任何查找。通常调用logger.info("Try ${date:YYYY-MM-dd}")会将日期模板${date:YYYY-MM-dd}替换为实际日期。使用nollookup将禁用此功能，并记录未更改的消息字符串。

2.3.2. %x

x有两种形式：

  • x
  • NDC

输出与生成日志事件的线程关联的线程上下文堆栈（也称为嵌套诊断上下文或NDC）。

2.3.3. Throwable{separator(|)}

throwable 有三种形式：

  • ex
  • exception
  • throwable

另外还有四种后缀

{
  [ "none"
   | "full"
   | depth
   | "short"
   | "short.className"
   | "short.fileName"
   | "short.lineNumber"
   | "short.methodName"
   | "short.message"
   | "short.localizedMessage"]
}
{filters(package,package,...)}
{suffix(pattern)}
{separator(separator)}

输出绑定到日志事件的 Throwable 跟踪，默认情况下，这将输出完整的跟踪，就像调用Throwable.printstacktrace()一样。

你可以在 throwable 转换词后面加上一个形式为%throwable{option}的选项。

%throwable{short}输出 Throwable 的第一行。

%throwable{short.className}输出发生异常的类的名称。

%throwable{short.methodName}输出发生异常的方法名。

%throwable{short.fileName}输出发生异常的类的名称。

%throwable{short.lineNumber}输出发生异常的行号。

%throwable{short.message}输出消息。

%throwable{short.localizedMessage}输出本地化消息。

%throwable{n}输出栈跟踪的前 n 行。

指定%throwable{none}或%throwable{0}将抑制异常的输出。

使用{filters(packages)}，其中 packages 是一个包名列表，以禁止从堆栈跟踪中匹配堆栈帧。

使用{suffix(pattern)}在每个堆栈帧的末尾添加模式输出。

使用{separator(…)}作为行尾字符串。例如：分隔符(|)。默认值是 line.separator系统属性，它依赖于操作系统。

2.4. 本地测试

2.4.1. 配置依赖

采用 SpringBoot 项目进行测试，首先配置 Log4j2 的依赖。

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter</artifactId>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

测试代码：

package com.example.demo;

import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class DemoApplication implements CommandLineRunner {
    public static void main(String[] args) {
        SpringApplication.run(DemoApplication.class, args);
    }

    @Override
    public void run(String... args) throws Exception {
        int i = 1 / 0;
    }
}

添加一个log4j2.properties配置文件，并且在application.properties文件中添加：

logging.config=classpath:log4j2.properties

2.4.2. 堆栈分开

提供log4j2.properties配置文件，主要内容：

appender.console.type=Console
appender.console.name=STDOUT
appender.console.target=SYSTEM_OUT
appender.console.layout.type=PatternLayout
appender.console.layout.pattern=%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %-60c - %m%n

日志打印效果：

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-07-30 20:25:25,460 [main] ERROR org.springframework.boot.SpringApplication                   - Application run failed
java.lang.IllegalStateException: Failed to execute CommandLineRunner
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798) [spring-boot-2.5.0.jar:2.5.0]
	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:779) [spring-boot-2.5.0.jar:2.5.0]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:344) [spring-boot-2.5.0.jar:2.5.0]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1336) [spring-boot-2.5.0.jar:2.5.0]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1325) [spring-boot-2.5.0.jar:2.5.0]
	at com.example.demo.DemoApplication.main(DemoApplication.java:10) [classes/:?]
Caused by: java.lang.ArithmeticException: / by zero
	at com.example.demo.DemoApplication.run(DemoApplication.java:15) ~[classes/:?]
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:795) ~[spring-boot-2.5.0.jar:2.5.0]
	... 5 more

2.4.3. 堆栈合并

提供log4j2.properties配置文件，主要内容：

appender.console.type=Console
appender.console.name=STDOUT
appender.console.target=SYSTEM_OUT
appender.console.layout.type=PatternLayout
appender.console.layout.pattern=%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %-60c - %m{nolookups}%xThrowable{separator(|)}%n

日志打印效果：

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-07-30 20:20:27,495 [main] ERROR org.springframework.boot.SpringApplication                   - Application run failed java.lang.IllegalStateException: Failed to execute CommandLineRunner|	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798) [spring-boot-2.5.0.jar:2.5.0]|	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:779) [spring-boot-2.5.0.jar:2.5.0]|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:344) [spring-boot-2.5.0.jar:2.5.0]|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1336) [spring-boot-2.5.0.jar:2.5.0]|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1325) [spring-boot-2.5.0.jar:2.5.0]|	at com.example.demo.DemoApplication.main(DemoApplication.java:10) [classes/:?]|Caused by: java.lang.ArithmeticException: / by zero|	at com.example.demo.DemoApplication.run(DemoApplication.java:15) ~[classes/:?]|	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:795) ~[spring-boot-2.5.0.jar:2.5.0]|	... 5 more|

3. Logback

参考地址：How do I remove newline from Java stacktraces in logback?

3.1. 问题描述

我想要从 Java 堆栈跟踪信息中删除换行符。使用的是 logback 模式：

<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %replace(%msg){'\n', ''}%n</pattern>

我希望它能替换消息中的换行符，但它没起作用，我看到的还是用换行符打印的堆栈跟踪。但是，如果我使用以下模式(仅用于测试目的)：

<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %replace(%msg){'.*', 'x'}%n</pattern>

我发现消息的换行符已被替换为字符x，但是堆栈跟踪仍按原样打印。

这使我相信 logback 对堆栈跟踪的处理是独立的。我浏览了 logback 文档，该文档指出可以通过(％ex)引用堆栈跟踪记录。但是，随后我只能使追加程序一次处于活动状态。如何确保在堆栈跟踪中没有换行符？

3.2. 解决方案

<pattern>........ %m%replace(%ex{full}){"[\r\n]+", "###"}"%nopex%n</pattern>

说明：

  • ex{full}：{}中指定需要打印的异常行数，full为全部异常信息。
  • %nopex：处理多余的堆栈输出信息，不加这个的话，堆栈信息重复输出一遍，且存在换行。
  • {"[\r\n]+", "###"}：替换异常信息中的换行符为###。

3.3. 本地测试

同样的测试代码，参考上面测试 Log4j2 的代码，SpringBoot 默认支持 Logback，我们只需要提供一个logback-spring.xml文件。然后删除 Log4j2 的相关配置即可。

3.3.1. 堆栈分开

logback-spring.xml的配置：

<appender name="ConsoleOut" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{"yyyy-MM-dd HH:mm:ss,SSS"} [%t] %-5p %-60c - %m%n</pattern>
        <charset>UTF-8</charset>
    </encoder>
</appender>

日志打印效果：

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-07-30 20:53:08,682 [main] ERROR org.springframework.boot.SpringApplication                   - Application run failed
java.lang.IllegalStateException: Failed to execute CommandLineRunner
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798)
	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:779)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:344)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1336)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1325)
	at com.example.demo.DemoApplication.main(DemoApplication.java:10)
Caused by: java.lang.ArithmeticException: / by zero
	at com.example.demo.DemoApplication.run(DemoApplication.java:15)
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:795)
	... 5 common frames omitted

3.3.2. 堆栈合并

logback-spring.xml的配置：

<appender name="ConsoleOut" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{"yyyy-MM-dd HH:mm:ss,SSS"} [%t] %-5p %-60c - %m%replace(%ex{full}){"[\r\n]+", "|"}"%nopex%n</pattern>
        <charset>UTF-8</charset>
    </encoder>
</appender>

日志打印效果：

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled."
2021-07-30 21:02:08,817 [main] ERROR org.springframework.boot.SpringApplication                   - Application run failedjava.lang.IllegalStateException: Failed to execute CommandLineRunner|	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798)|	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:779)|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:344)|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1336)|	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1325)|	at com.example.demo.DemoApplication.main(DemoApplication.java:10)|Caused by: java.lang.ArithmeticException: / by zero|	at com.example.demo.DemoApplication.run(DemoApplication.java:15)|	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:795)|	... 5 common frames omitted|"

可以看出已经生效，只是具体日志和 Log4j2 打印出来的有略微的区别。

avatar
文章
阅读
粉丝