Spring Boot项目中使用Logback日志与使用AOP拦截请求日志信息

日志记录了系统行为的时间、地点等很多细节的具体信息，在发生错误或者接近某种危险状态时能够及时提醒开发人员处理，往往在系统产生问题时承担问题定位与诊断和解决的重要角色。

一般很多线上的问题只能通过进行日志分析才可以解决的，所以需要明确日志在日常开发环节中是十分重要的。

1.常用的日志框架

常用的日志框架一般包括：Commons Logging、Slf4j、Log4j，Log4j2，Logback。

日志框架一般分为日志门面和对应的具体实现两部分，所谓日志门面就是门面模式的一个典型的应用，门面模式也称为外观模式，而日志门面框架就是一套提供了日志相关功能的接口而无具体实现的框架，日志记录是通过调用具体的实现框架来进行的。

典型的日志门面就是 Commons Logging、SLF4J，具体的实现就是Logback、Log4j 。比较常用的组合方式是 Slf4j 和 Logback 的组合使用，Commons Logging 与 Log4j 的组合使用，并且 Logback 必须得配合 Slf4j 使用。

Logback 是由 log4j 的创始人编写的，但是性能上的话会比 log4j 更好一些，他主要分为有三个模块：

• logback-core：核心代码模块。
• logback-classic：log4j 的一个改良版本，同时实现了 slf4j 的接口。
• logback-access：这是 logback 的访问模块，它与 Servlet 容器集成并且提供通过 Http 来访问日志的功能。

slf4j 是标准，对用户提供统一的 API，而下方对接各个日志框架。严格意义上说 slf4j 自身并不提供日志具体实现，在 Logback 的模块里面，logback-classic 就是实现了 slf4j 具体接口的核心模块。它可以自动重新加载配置文件，如果开发过程中配置文件修改了，logback-classic 能自动重新加载配置文件，扫描过程快且安全。

2.Spring Boot项目整合Logback日志框架的使用

2.1 添加依赖

在spring boot项目中，我们不用再单独引入相关依赖，因为在spring boot项目的启动依赖中包含了该日志框架的相关依赖。spring-boot-starter 就已经包含了 spring-boot-starter-logging，而 spring-boot-starter-logging 中引用了 Logback 的依赖。

2.2 添加配置文件

在 resources 文件夹下面新建配置文件信息，来配置我们的 Logback。

<?xml version="1.0" encoding="UTF-8"?>
<configuration>


    <property name="FILE_ERROR_PATTERN"
              value="${FILE_LOG_PATTERN:-%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%t] %-40.40logger{39} %file:%line: %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>


    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
        </filter>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <appender name="FILE_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--如果只是想要 Info 级别的日志，只是过滤 info 还是会输出 Error 日志，因为 Error 的级别高， 所以我们使用下面的策略，可以避免输出 Error 的日志-->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <!--过滤 Error-->
            <level>ERROR</level>
            <!--匹配到就禁止-->
            <onMatch>DENY</onMatch>
            <!--没有匹配到就允许-->
            <onMismatch>ACCEPT</onMismatch>
        </filter>
        <!--日志名称，如果没有File 属性，那么只会使用FileNamePattern的文件路径规则如果同时有<File>和<FileNamePattern>，那么当天日志是<File>，明天会自动把今天的日志改名为今天的日期。即，<File> 的日志都是当天的。-->
        <!--<File>logs/info.spring-boot-logback.log</File>-->
        <!--滚动策略，按照时间滚动 TimeBasedRollingPolicy-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--文件路径,定义了日志的切分方式——把每一天的日志归档到一个文件中,以防止日志填满整个磁盘空间-->
            <FileNamePattern>logs/spring-boot-logback/info.created_on_%d{yyyy-MM-dd}.part_%i.log</FileNamePattern>
            <!--只保留最近90天的日志-->
            <maxHistory>90</maxHistory>
            <!--用来指定日志文件的上限大小，那么到了这个值，就会删除旧的日志-->
            <!--<totalSizeCap>1GB</totalSizeCap>-->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <!-- maxFileSize:这是活动文件的大小，默认值是10MB -->
                <maxFileSize>2MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <!--<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">-->
        <!--<maxFileSize>1KB</maxFileSize>-->
        <!--</triggeringPolicy>-->
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset> <!-- 此处设置字符集 -->
        </encoder>
    </appender>

    <appender name="FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--如果只是想要 Error 级别的日志，那么需要过滤一下，默认是 info 级别的，ThresholdFilter-->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>Error</level>
        </filter>
        <!--日志名称，如果没有File 属性，那么只会使用FileNamePattern的文件路径规则如果同时有<File>和<FileNamePattern>，那么当天日志是<File>，明天会自动把今天的日志改名为今天的日期。即，<File> 的日志都是当天的。-->
        <!--<File>logs/error.spring-boot-logback.log</File>-->
        <!--滚动策略，按照时间滚动 TimeBasedRollingPolicy-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--文件路径,定义了日志的切分方式——把每一天的日志归档到一个文件中,以防止日志填满整个磁盘空间-->
            <FileNamePattern>logs/spring-boot-logback/error.created_on_%d{yyyy-MM-dd}.part_%i.log</FileNamePattern>
            <!--只保留最近90天的日志-->
            <maxHistory>90</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <!-- maxFileSize:这是活动文件的大小，默认值是10MB,本篇设置为1KB，只是为了演示 -->
                <maxFileSize>2MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>${FILE_ERROR_PATTERN}</pattern>
            <charset>UTF-8</charset> <!-- 此处设置字符集 -->
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="FILE_INFO"/>
        <appender-ref ref="FILE_ERROR"/>
    </root>
</configuration>

2.3 使用日志框架

@SpringBootApplication
@Slf4j
public class SpringaopApplication {

    public static void main(String[] args) {
        ConfigurableApplicationContext context =  SpringApplication.run(SpringaopApplication.class, args);

        int length = context.getBeanDefinitionNames().length;
        log.trace("Spring boot启动初始化了 {} 个 Bean", length);
        log.debug("Spring boot启动初始化了 {} 个 Bean", length);
        log.info("Spring boot启动初始化了 {} 个 Bean", length);
        log.warn("Spring boot启动初始化了 {} 个 Bean", length);
        log.error("Spring boot启动初始化了 {} 个 Bean", length);
        try {
            int i = 0;
            int j = 1 / i;
        } catch (Exception e) {
            log.error("【SpringBootApplication】启动异常：", e);
        }
    }
}

启动项目，查看日志内容。

以及在logs文件夹下会生成日记文件

3. Spring Boot项目使用AOP拦截请求日志信息

AOP的整体内容主要包含以下几点：

Pointcut：切点，主要是决定处理如权限校验、日志记录等在何处切入业务代码中（即织入切面）。切点分为 execution 方式和 annotation 方式。前者可以用路径表达式指定哪些类织入切面，后者可以指定被哪些注解修饰的代码织入切面。

Advice：处理（通知），包括处理时机和处理内容。处理内容就是要做什么事，比如校验权限和记录日志。处理时机就是在什么时机执行处理内容，分为前置处理（即业务代码执行前）、后置处理（业务代码执行后）等。这也回答了我们之前提到的什么时候切入，切入过后应该要做哪些事情。

Aspect：切面，即 Pointcut 和 Advice,在代码中就是我们定义的这个切面的类，选择在什么地方织入。

Joint point：连接点，是程序执行的一个点。例如，一个方法的执行或者一个异常的处理。在 AOP 中，一个连接点总是代表着一个方法执行。

Weaving：织入，就是通过动态代理的方式在目标对象方法中执行处理内容的过程。

添加AOP的相关依赖。

		<dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>

创建controller包与aspectj包，首先在controller包下创建测试控制器。

@RestController
public class TestController {


    @GetMapping("/test")
    public Dict test(@RequestParam String who){
        return Dict.create().set("who", StrUtil.isAllBlank(who) ? "me" : who);
    }
}

接下来在 aspectj 这个包中新建 AOP 相关的类： AopLog.java 利用这个类我们来记录请求日志的信息。

@Aspect
@Component
@Slf4j
public class AopLog {

    private static final String START_TIME = "request-start";

    /**
     * 切入点
     */
    @Pointcut("execution(public * com.picacho.springaop.controller.*Controller.*(..))")
    public void log() {

    }

    /**
     * 前置操作
     * @param point
     */
    @Before("log()")
    public void beforeLog(JoinPoint point) {
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();

        HttpServletRequest request = Objects.requireNonNull(attributes).getRequest();

        log.info("【请求 URL】：{}", request.getRequestURL());
        log.info("【请求 IP】：{}", request.getRemoteAddr());
        log.info("【请求类名】：{}，【请求方法名】：{}", point.getSignature().getDeclaringTypeName(), point.getSignature().getName());

        Map<String, String[]> parameterMap = request.getParameterMap();
        log.info("【请求参数】：{}，", JSONUtil.toJsonStr(parameterMap));
        Long start = System.currentTimeMillis();
        request.setAttribute(START_TIME, start);
    }


    /**
     * 环绕操作
     * @param point
     * @return
     * @throws Throwable
     */
    @Around("log()")
    public Object aroundLog(ProceedingJoinPoint point) throws Throwable {
        Object result = point.proceed();
        log.info("【返回值】：{}", JSONUtil.toJsonStr(result));
        return result;
    }

    /**
     * 后置操作
     */
    @AfterReturning("log()")
    public void afterReturning() {
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = Objects.requireNonNull(attributes).getRequest();

        Long start = (Long) request.getAttribute(START_TIME);
        Long end = System.currentTimeMillis();
        log.info("【请求耗时】：{}毫秒", end - start);

        String header = request.getHeader("User-Agent");
        UserAgent userAgent = UserAgent.parseUserAgentString(header);
        log.info("【浏览器类型】：{}，【操作系统】：{}，【原始User-Agent】：{}", userAgent.getBrowser().toString(), userAgent.getOperatingSystem().toString(), header);
    }

}

启动项目测试效果：


最后再观察一下日志文件。

好了，这个demo到这里也就结束了，虽然这里只是简单的使用，但是在一个完整的项目中日志和AOP也基本同样采用这种方案。
源码下载地址：源码下载