SpringBoot程序日志

Naylor10个月前发布

250

[toc]

概述

Slf4j简介

Java的简单日志记录外观（Simple Logging Facade for Java ）可作为各种日志记录框架（例如java.util.logging，logback，log4j，log4j2）的简单外观或抽象，允许终端用户在开发时插拔所需的日志记录框架。简单来说，Slf4j定义了一种规范，java程序在记录日志时候的规范，这种规范是一个空壳，在实际开发中需要集成具体的日志框架来干活，这种具体的日志框架需要满足一些标准：符合Slf4j定义的标准；能够提供日志记录的功能。

Logback简介

一个“可靠、通用、快速而又灵活的Java日志框架”。logback是log4j的升级迭代产品，在许多地方相比于log4j有优势：

1：性能，提升近10倍，初始内存减少了许多
2：对Slf4j友好，同时引用这两个框架之后，甚至不需要额外的配置就可以很融洽的运行起来
3：自动重新加载配置文件
4：强大的研发团队和完善的文档

logback的三大核心模块：

logback-classic：log4j的一个改良版本，同时整合了对Slf4j的支持
logback-access：Servlet容器集成提供通过HTTP来访问日志的功能
logback-core：其他两个模块的基础模块

日志级别

Trace：轻微错误。
Debug：调试日志，主要用于开发过程中打印一些运行信息。
Info：突出强调应用程序的运行过程，打印一些你感兴趣的或者重要的信息。
Warn：潜在错误。其实没有发生错误，只是给编码人员一些警告和提示。
Error：虽然发生错误事件，但仍然不影响系统的继续运行，记录错误现场。
Fatal：致命错误。

常用日志级别：info，debug，error

高日志级别可以打印使用低级别记录的日志。若设置的日志级别为info，同时打印三种（debug,info,error）只可以输出info和error。这是因为Debug的日志级别比info高，低日志级别无法打印使用高级别记录的日志。

基本实践

当我们新建一个 SpringBoot 应用程序之后，可以发现已经为我们装配了 slf4j 和 logback

spring-boot-starter-logging 和 logback，slf4j 的依赖关系：

此时可以直接使用 log.info 、log.debug 、log.error 来打印日志。


@Slf4j
@SpringBootApplication
public class Slf4jLogbackApplication {
    public static void main(String[] args) {
        SpringApplication.run(Slf4jLogbackApplication.class, args);
        log.info("info-log");
        log.debug("debug-log");
        log.error("error-log");
    }
}

输出：


2023-07-03 11:32:30.256  INFO 14084 --- [           main] c.r.s.Slf4jLogbackApplication            : info-log
2023-07-03 11:32:30.256 ERROR 14084 --- [           main] c.r.s.Slf4jLogbackApplication            : error-log

可以看到控制台已经打印了我们编写的日志了，但是debug级别的日志没有打印。

此时可以通过修改日志级别将debug日志打印出来，需要修改配置文件，并新增如下内容：


logging:
  level:
    com.ramble : debug

输出：


2023-07-03 11:34:21.479  INFO 22264 --- [           main] c.r.s.Slf4jLogbackApplication            : info-log
2023-07-03 11:34:21.479 DEBUG 22264 --- [           main] c.r.s.Slf4jLogbackApplication            : debug-log
2023-07-03 11:34:21.479 ERROR 22264 --- [           main] c.r.s.Slf4jLogbackApplication            : error-log

当我们调整了日志级别之后，debug也显示出来了。

但是现在如果在项目中使用还有诸多问题，日志只能记录在控制台，无法记录在文件中。

进阶实践

logback-spring.xml

在resource下新建一个 logback-spring.xml 的配置文件


<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="encoding" value="UTF-8"/>
    <!-- 读取application.yml中的 spring.application.name 属性，如果没有配置，默认值为 ngh -->
    <springProperty scope="context" name="applicationName" source="spring.application.name" defaultValue="app"/>
    <!--定义日志文件的存储地址 勿在LogBack的配置中使用相对路径-->
    <property name="LOG_HOME" value="./logs/${applicationName}"/>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 过滤日志 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <!-- 如果命中就禁止这条日志 -->
            <onMatch>DENY</onMatch>
            <!-- 如果没有命中就使用这条规则 -->
            <onMismatch>ACCEPT</onMismatch>
        </filter>
        <Append>true</Append>
        <prudent>false</prudent>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd/HH:mm:ss.SSS}|%X{localIp}|%X{requestId}|%X{requestSeq}|^_^|[%t] %-5level %logger{50}%line - %m%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>256MB</maxFileSize>
            <maxHistory>15</maxHistory>
            <totalSizeCap>32GB</totalSizeCap>
        </rollingPolicy>
    </appender>
    <appender name="ACCESS_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <Append>true</Append>
        <prudent>false</prudent>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd/HH:mm:ss.SSS}|%X{localIp}|%X{requestId}|%X{requestSeq}|^_^|[%t] %-5level %logger{50}%line - %m%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/access-log-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>256MB</maxFileSize>
            <maxHistory>15</maxHistory>
            <totalSizeCap>32GB</totalSizeCap>
        </rollingPolicy>
    </appender>
    <appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <Append>true</Append>
        <prudent>false</prudent>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd/HH:mm:ss.SSS}|%X{localIp}|%X{requestId}|%X{requestSeq}|^_^|[%t] %-5level %logger{50}%line - %m%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>256MB</maxFileSize>
            <maxHistory>15</maxHistory>
            <totalSizeCap>32GB</totalSizeCap>
        </rollingPolicy>
    </appender>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %5p %c.%M:%L - %m%n</pattern>
        </encoder>
    </appender>
    <root additivity="false" level="INFO">
        <appender-ref ref="FILE"/>
        <appender-ref ref="ERROR"/>
        <appender-ref ref="STDOUT"/>
    </root>
    <logger name="AccessLog" additivity="false">
        <appender-ref ref="ACCESS_LOG"/>
    </logger>
</configuration>

可以显式指定配置文件路径

   
   logging:  
      config: classpath:logback-spring.xml

如果在 IDEA 中运行可能会发现根目录没有创建 logs 文件夹，也没有生成日志文件，尝试用命令行启动试试，或者干脆指定一个绝对路径

记录方法出入参

pom


<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>
<dependency>
    <groupId>com.alibaba</groupId>
    <artifactId>fastjson</artifactId>
    <version>1.2.76</version>
</dependency>
<dependency>
    <groupId>org.apache.commons</groupId>
    <artifactId>commons-collections4</artifactId>
    <version>4.1</version>
</dependency>
<dependency>
    <groupId>org.apache.commons</groupId>
    <artifactId>commons-lang3</artifactId>
    <version>3.5</version>
</dependency>
<dependency>
    <groupId>commons-collections</groupId>
    <artifactId>commons-collections</artifactId>
    <version>3.2.2</version>
</dependency>
<dependency>
    <groupId>org.apache.commons</groupId>
    <artifactId>commons-lang3</artifactId>
    <version>3.7</version>
</dependency>

增加Aop

新建一个类 LogAspect ，用来自动记录方法的出入参。

logger ：实例化在logback-spring.xml 中定义的 accessLog ，将使用accessLog记录所有方法出入参的日志
ignoreMethods：某些方法可能不需要或者不允许记录到日志中，例如登录方法、修改密码方法、上传下载方法
sensitiveWords：若返回值中存在敏感词汇，将不记录到日志中
maxLimit和minLimit：如果所有的日志都记录，log文件将特别的大，很容易撑爆硬盘，方法返回值超过100k的将只记录前1k的内容
doBefore：记录入参，通过@Before可以限定此切面覆盖的方法
doAfterReturn：记录出参，通过@AfterReturning可以限定此切面覆盖的方法
使用@Component注解添加到容器


package com.ramble.slf4jlogback.aspect;
import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.serializer.SerializerFeature;
import com.ramble.slf4jlogback.constant.LogPropertyFilter;
import com.ramble.slf4jlogback.util.ObjectUtil;
import org.apache.commons.collections.CollectionUtils;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import java.lang.reflect.Modifier;
import java.util.Collection;
import java.util.Map;

@Aspect
@Component
public class LogAspect {

    /**
     * 使用单独的  accesslog 记录
     */
    private static final Logger logger = LoggerFactory.getLogger("AccessLog");
    
    /**
     * 需要排除的方法
     */
    private static final String[] ignoreMethods = new String[]{"login", "changePassword", "modifyPassword", "uploadFile"};
    
    /**
     * 敏感词不记录
     */
    private static final String[] sensitiveWords = new String[]{"password", "token", "base64"};
    
    /**
     * 大于100K的log不显示
     */
    private static final Integer maxLimit = 1024 * 100;
    
    /**
     * 对于大于100K的log，仅仅截取前1K的数据记录到log
     */
    private static final Integer minLimit = 1024;
    
    /**
     * 统一记录 controller 层方法入参
     * @param jp
     */
    @Before("execution(* com.ramble..controller..*.*(..))")
    public void doBefore(JoinPoint jp) {
        Signature signature = jp.getSignature();
        if (signature != null) {
            StringBuilder log = new StringBuilder(" enter className:");
            String className = signature.getDeclaringTypeName();
            log.append(className);
            String methodName = signature.getName();
            log.append(",methodName:").append(methodName);
            if (!ignoreMethod(methodName)) {
                //region  排除含有敏感信息的参数输出逻辑
                String argStr = JSON.toJSONString(jp.getArgs(), LogPropertyFilter.LOG_FILE_FILTER, SerializerFeature.WriteClassName);
                // 排除含有敏感信息的参数输出
                if (!containsSensitiveWords(argStr)) {
                    log.append(",args:").append(argStr);
                } else {
                    log.append(",args:").append("sensitive word in args and forbidden to print.");
                }
                //endregion
//                String argStr = JSON.toJSONString(jp.getArgs(), SerializerFeature.WriteClassName);
//                log.append(",args:").append(argStr);
            } else {
                log.append(",args:").append("ignore method and forbidden to print args.");
            }
            String logStr = log.toString();
            if (Modifier.isPublic(signature.getModifiers())) {
                logger.info("####### {}", logStr);
            } else {
                logger.debug("####### {}", logStr);
            }
        }
    }
    
    
    /**
     * 统一记录 controller 层方法出参
     * @param jp
     * @param returnValue
     */
    @AfterReturning(value = "execution(* com.ramble..controller..*.*(..))", returning = "returnValue")
    public void doAfterReturn(JoinPoint jp, Object returnValue) {
        Signature signature = jp.getSignature();
        if (signature != null) {
            StringBuilder log = new StringBuilder("leave className:");
            String className = signature.getDeclaringTypeName();
            log.append(className);
            String methodName = signature.getName();
            log.append(",methodName:").append(methodName);
            // 排除含有敏感信息的log输出
            if (!ignoreMethod(methodName)) {
                String argStr = ObjectUtil.toString(jp.getArgs());
                //region
                if (!containsSensitiveWords(argStr)) {
                    log.append(",args:").append(argStr);
                } else {
                    log.append(",args:").append("sensitive word in args and forbidden to print.");
                }
                //endregion
            } else {
                log.append(",args:").append("ignore method and forbidden to print args.");
            }
            log.append(",return:");
            if (null != returnValue) {
                log.append(returnValue.getClass().getName() + ":");
                if (returnValue instanceof Collection) {
                    log.append("/size:").append(CollectionUtils.size(returnValue));
                } else if (returnValue instanceof Map) {
                    log.append("/size:").append(CollectionUtils.size(((Map) returnValue).entrySet()));
                } else {
                    String resStr = returnValue.toString();
                    //log.append(resStr);
                    //region
                    String printStr = null;
                    if (!containsSensitiveWords(resStr)) {
                        if (resStr.length() > maxLimit) {
                            printStr = resStr.substring(0, minLimit);
                        } else {
                            printStr = resStr;
                        }
                        log.append(printStr);
                    } else {
                        log.append("sensitive word in response and forbidden to print.");
                    }
                    //endregion
                }
            } else {
                log.append("");
            }
            String logStr = log.toString();
            if (Modifier.isPublic(signature.getModifiers())) {
                logger.info("####### {}", logStr);
            } else {
                logger.debug("####### {}", logStr);
            }
        }
    }
    
    
    /**
     * 过滤不记录入参出参的方法
     * @param methodName
     * @return
     */
    private boolean ignoreMethod(String methodName) {
        boolean result = false;
        if (null != ignoreMethods && ignoreMethods.length > 0) {
            for (String checkMethod : ignoreMethods) {
                if (checkMethod.equalsIgnoreCase(methodName)) {
                    result = true;
                    break;
                }
            }
        }
        return result;
    }
    
    
    /**
     * 过滤掉含有敏感信息的方法
     * @param sensiWord
     * @return
     */
    private boolean containsSensitiveWords(String sensiWord) {
        boolean result = false;
        if (null != sensitiveWords && sensitiveWords.length > 0) {
            for (String checkWord : sensitiveWords) {
                if (sensiWord.contains(checkWord)) {
                    result = true;
                    break;
                }
            }
        }
        return result;
    }
    
    
}

增加序列化过滤器

在序列化的时候需要排除文件


package com.ramble.slf4jlogback.constant;
import org.springframework.web.multipart.MultipartFile;
import com.alibaba.fastjson.serializer.PropertyFilter;

public enum LogPropertyFilter implements PropertyFilter{

    LOG_FILE_FILTER();
    
    @Override
    public boolean apply(Object object, String name, Object value) {
        return !(object instanceof MultipartFile);
    }
}

增加工具类

ObjectUtil


package com.ramble.slf4jlogback.util;
import org.apache.commons.collections.CollectionUtils;
import org.apache.commons.lang3.ArrayUtils;
import org.apache.commons.lang3.StringUtils;
import java.util.Collection;
import java.util.Map;

public abstract class ObjectUtil {

    public static String toString(Object[] array) {
        StringBuilder sb = new StringBuilder("[");
        if (ArrayUtils.isNotEmpty(array)) {
            for (Object obj : array) {
                if (null != obj) {
                    if (obj instanceof Collection) {
                        sb.append(obj.getClass().getName());
                        sb.append("/size:").append(CollectionUtils.size(obj));
                    } else if (obj instanceof Map) {
                        sb.append(obj.getClass().getName());
                        sb.append("/size:").append(CollectionUtils.size(((Map) obj).entrySet()));
                    } else {
                        sb.append(obj.toString());
                    }
                    sb.append(", ");
                }
            }
        }
        String str = StringUtils.trim(sb.toString());
        if (StringUtils.endsWithIgnoreCase(str, ",")) {
            str = StringUtils.substringBeforeLast(str, ",");
        }
        return str + "]";
    }
}

增加一个controller


@Slf4j
@RestController
@RequestMapping("/test")
public class TestController {

    @GetMapping("/case1/{id}")
    public String case1(@PathVariable("id") String id) {
        log.info("coming - case1 ");
        return "ok";
    }
    
    @GetMapping("/login")
    public String login() {
        return "ok";
    }
    
    @GetMapping("/token")
    public String getToken() {
        return "token=123456";
    }
}

当分别调用这三个接口，将在 access-log-2023-07-03.0.log 文件中记录如下内容：


2023-07-03/16:49:53.219||||^_^|[http-nio-9009-exec-1] INFO  AccessLog93 - #######  enter className:com.ramble.slf4jlogback.controller.TestController,methodName:case1,args:["888"]
2023-07-03/16:49:53.236||||^_^|[http-nio-9009-exec-1] INFO  AccessLog157 - ####### leave className:com.ramble.slf4jlogback.controller.TestController,methodName:case1,args:[888],return:java.lang.String:ok
2023-07-03/16:50:06.806||||^_^|[http-nio-9009-exec-3] INFO  AccessLog93 - #######  enter className:com.ramble.slf4jlogback.controller.TestController,methodName:login,args:ignore method and forbidden to print args.
2023-07-03/16:50:06.807||||^_^|[http-nio-9009-exec-3] INFO  AccessLog157 - ####### leave className:com.ramble.slf4jlogback.controller.TestController,methodName:login,args:ignore method and forbidden to print args.,return:java.lang.String:ok
2023-07-03/16:50:10.827||||^_^|[http-nio-9009-exec-2] INFO  AccessLog93 - #######  enter className:com.ramble.slf4jlogback.controller.TestController,methodName:getToken,args:[]
2023-07-03/16:50:10.827||||^_^|[http-nio-9009-exec-2] INFO  AccessLog157 - ####### leave className:com.ramble.slf4jlogback.controller.TestController,methodName:getToken,args:[],return:java.lang.String:sensitive word in response and forbidden to print.

通过输出的日志可以观察到：

自动记录了出入参
可以设置白名单，即白名单中的方法不会记录日志
可以设置敏感词，一旦检测到敏感词不会记录到日志中
可以设置出参记录到文件中的大小限制，避免资源过渡消耗、影响程序性能

业务日志聚合

在实际开发中是否遇到过这样的问题：

当日志很多的时候，我们很难从info或者debug日志文件中找出我们想看的日志
所有业务模块的日志都输出到了同一个日志文件中，日志和业务模块无法区分
……

如果我们能将日志文件的管理维度更加细化，也许可以减轻查看日志时候的痛苦，一种办法是采用业务日志分类聚合，另一种办法是搭建一个日志管理系统，例如使用filebeat+es+kibana。

对于业务日志分类聚合可以使用如下的方式：

在 logback-spring.xml 文件中定义不同的 logger
在特定业务代码中实例化基于业务划分的 logger ，并用此logger记录日志
或者，使用 slf4j(“logger”)方式指定此类中要使用的logger

代码参考：


private static final Logger logger = LoggerFactory.getLogger("AccessLog");

@Slf4j("AccessLog")

思考

如何使用 Filebeat 将日志文件（指硬盘中存储的 xxx.log 文件）同步到 ElasticSearch ？
无论何种方式将日志同步到 ElasticSearch ，如何引入消息队列来削峰？
ElasticSearch 中存储的日志数据，如何给开发同事浏览（kibana？自建日志查看系统？）

引用

logback-elasticsearch-appender官网：https://github.com/internetitem/logback-elasticsearch-appender

评分

欢迎为Ta评分