SpringBoot项目日志输出为JSON格式，方便Elastic采集

Posted 2022-02-10 北亮bl

这段时间，使用K8S部署项目，同时使用Elastic采集日志并提供给开发检索，使用过程中，经常出现换行日志无法完整采集和展示的问题。
比如抛出的Exception会有换行，被ES采集后，变成多条日志，极其不方便检索和排错。

经运维提示，并参考 https://groups.google.com/g/fluent-bit/c/XoOibAxGGeI
改用json输出项目日志，本地调试依然使用旧日志格式。
注：本文基于：
spring-boot-starter:2.4.11 或 spring-boot-starter:2.3.10.RELEASE

1、打开项目pom.xml，添加依赖：

<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>6.4</version>
</dependency>

2、在项目的resources目录下，添加文件 logback-spring.xml
注：文件名不允许是 logback.xml ，否则会报错：
no applicable action for [springProfile], current ElementPath is [[configuration][springProfile]]
文件内容参考：

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
    <appender name="JsonAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <fieldNames>
                <timestamp>dt</timestamp>
                <version>[ignore]</version>
                <levelValue>[ignore]</levelValue>
                <stackTrace>exp</stackTrace>
            </fieldNames>
            <!-- This 'fixes' double quote problem for elastic -->
            <jsonFactoryDecorator class="net.logstash.logback.decorate.CharacterEscapesJsonFactoryDecorator">
                <escape>
                    <targetCharacterCode>34</targetCharacterCode>
                    <escapeSequence>'</escapeSequence>
                </escape>
            </jsonFactoryDecorator>
            <!-- This shortens extremely long stacktraces. Not always needed -->
            <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                <maxDepthPerThrowable>30</maxDepthPerThrowable>
                <maxLength>2048</maxLength>
                <shortenedClassNameLength>20</shortenedClassNameLength>
                <exclude>sun\\.reflect\\..*\\.invoke.*</exclude>
                <exclude>net\\.sf\\.cglib\\.proxy\\.MethodProxy\\.invoke</exclude>
                <rootCauseFirst>true</rootCauseFirst>
                <inlineHash>true</inlineHash>
            </throwableConverter>
        </encoder>
    </appender>
    <root level="INFO">
        <!-- 配置文件的：spring.profiles.active为local时，本地输出标准格式 -->
        <springProfile name="local">
            <appender-ref ref="CONSOLE"/>
        </springProfile>
        <!-- 其它环境输出json格式 -->
        <springProfile name="!local">
            <appender-ref ref="JsonAppender"/>
        </springProfile>
    </root>
</configuration>

OK，构建项目就可以看到输出的都是JSON格式了：
正常的INFO日志如下：

"dt":"2022-01-19T14:46:34.762+08:00","message":"请求:/v2/test | 返回='status':'0','success':true","logger_name":"beinet.cn.web.advice.WebResponseBodyAdvice","thread_name":"http-nio-80-exec-9","level":"INFO"

抛出的异常日志如下：

"dt":"2022-01-19T14:53:30.199+08:00","message":"testErr：","logger_name":"beinet.cn.weblog.IndexController","thread_name":"http-nio-8881-exec-2","level":"ERROR","exp":"<#56381f86> j.l.NumberFormatException: null\\r\\n\\tat java.lang.Integer.parseInt(Integer.java:614)\\r\\n\\tat java.lang.Integer.parseInt(Integer.java:770)...\\r\\n"

---

另：项目里使用了MyBatis-plus，需要输出SQL明细日志，之前是在配置里添加：

mybatis-plus:
  configuration:
    log-impl: org.apache.ibatis.logging.stdout.StdOutImpl # 输出SQL日志

这种是直接输出Console日志，也会影响采集，把它也改成JSON格式：

mybatis-plus:
  configuration:
    #log-impl: org.apache.ibatis.logging.stdout.StdOutImpl # 输出SQL日志
# mybatis-plus 输出sql日志在logback里
logging.level:
  beinet.cn.dal: debug  # 这是mybatis-plus的mapper类所在的package名

输出参考：

"dt":"2022-01-19T14:51:55.790+08:00","message":"==>  Preparing: select * from appinfo where app_key=?","logger_name":"beinet.cn.dal.AppInfoMapper.findByAppKey","thread_name":"http-nio-8881-exec-1","level":"DEBUG","tags":["MYBATIS"]
"dt":"2022-01-19T14:51:55.829+08:00","message":"==> Parameters: abc(String)","logger_name":"beinet.cn.dal.AppInfoMapper.findByAppKey","thread_name":"http-nio-8881-exec-1","level":"DEBUG","tags":["MYBATIS"]
"dt":"2022-01-19T14:51:55.929+08:00","message":"<==      Total: 1","logger_name":"beinet.cn.dal.AppInfoMapper.findByAppKey","thread_name":"http-nio-8881-exec-1","level":"DEBUG","tags":["MYBATIS"]