前言: 最近接手了工作室的招新系统项目, 其中有一个日志模块, 老师兄们实现了自定义Appender, 把日志记录到数据库. 我接手后, 了解了老师兄对日志的处理思路, 加上借助其他博客对logback自带的DBAppender的源码解析

Logback输出日志到自定义MySQL数据库（重写DBAppender）_logback日志输出到mysql数据库-CSDN博客

自己也改造了一下整个日志模块. 这个日志模块主要切接口(controller包及其所有子包下的方法), 记录接口的入参, 请求者以及返回结果等, 当然掌握思想后, 其他需要的地方可以单独切, 或者直接借助@Slf4j去直接记录.

1. 文章内容概要

  • Spring AOP在连接点相关参数和变量记录以及方法耗时统计上的应用(铺垫)
  • Logback配置文件的基本配置(铺垫)
  • 自定义Logback Appender(重点)
  • 切自定义注解实现记录自定义格式日志(重点)
  • Mybatis对于占位符的解析搬运到记录自定义日志上(难点)

2. Spring AOP在日志记录以及方法耗时统计上的应用

回顾一下什么是Spring AOP.

Spring AOP（Aspect-Oriented Programming，面向切面编程）是 Spring 框架中的一个核心模块，它提供了一种在应用程序中实现横切关注点（cross-cutting concerns）的方式。横切关注点是指那些在多个模块或类中重复出现的代码，例如日志记录、事务管理、安全性检查等。

在AOP中, 最重要的就是切面. 切面由下面几个元素构成.

2.1. 通知

一个通知定义了在切点处执行的代码.

  • Before 前置通知->在目标方法执行前
  • After 最终通知->在目标方法方法执行后, 无论如何都会执行
  • After Returning 后置通知->在目标方法返回之后立即执行, 优先于After
  • After Throwing 异常通知->在目标方法抛出异常后立即执行, 优先于After
  • Around Advice 环绕通知->环绕目标方法执行. 优先级最高

2.2. 切点

切点是一个表达式, 匹配到的方法即为这个切点下的所有连接点.

例如: 切点表达式 execution(* com.yourcompany.yourpackage.*.*(..)) 匹配 com.yourcompany.yourpackage 包下的所有方法。

切点可以切到包下的方法, 类中的方法, 带有某个注解的方法, 含有某种参数的方法, 也可以组合去切, 非常灵活.

2.3. 连接点

连接点就是确定的方法, 是程序执行过程的一个具体点, 比如方法调用或者构造方法. 切点(匹配表达式)下会匹配一组连接点(满足表达式的方法).

  • 连接点 是 AOP 框架可以插入切面逻辑的位置。
  • 切点 用于选择在这些连接点上应用通知。

基本概念过一遍, 实战中如何用AOP实现记录方法耗时以及记录日志呢?

2.4. 记录方法耗时

2.4.1 环绕通知

环绕通知可以在一个通知里说明对方法前后的操作, 甚至在通知里可以不执行目标方法方法, 或者更改目标方法的返回结果. 那么在环绕通知中, 只需要在方法执行前后调用System.currentTimeMillis()方法, 即可记录方法执行时间.

    @Around("execution(* com.example.MyService.*(..))")
    public Object aroundAdvice(ProceedingJoinPoint joinPoint) throws Throwable {
		long beginTime = System.currentTimeMillis();
        Object result = joinPoint.proceed(); // 执行目标方法
		long endTime = System.currentTimeMillis();      
        long duration = endTime - beginTime;
        //......
    }
2.4.2. 前后置通知

当我们想细分方法是正常返回还是抛出异常返回时, 如果不使用环绕通知, 而是使用前后置通知, 做法稍稍有些变化. 由于前后置通知是两个方法, 方法开始时间和结束时间作用域不同, 我们需要使用线程变量 ThreadLocal来记录当前线程的一些时间变量, 用于计算方法耗时.

首先在切面类中定义一个ThreadLocal<Date>类型的静态成员变量.

private static final ThreadLocal<Date> beginTimeThreadLocal = new NamedThreadLocal<>("ThreadLocal beginTime"); // NamedThreadLocal为ThreadLocal的子类, 区别不大

在前置通知中, 记录方法开始执行的时间.

@Before("controllerAspect()") // 切Controller包下的所有方法
public void doBefore() {
    //线程绑定变量（该数据只有当前请求的线程可见）
    Date beginTime = new Date();
    beginTimeThreadLocal.set(beginTime);
}

在后置通知中, 可以通过ThreadLocal拿到方法开始执行的时间, 结合方法结束的时间, 计算得到方法耗时.

@AfterReturning(value = "controllerAspect()", returning = "result")
public void after(JoinPoint joinPoint, Object result) {
    long endTime = System.currentTimeMillis();
    long beginTime = beginTimeThreadLocal.get().getTime();
    long duration = endTime - beginTime;
    //......
    beginTimeThreadLocal.remove();
}

ThreadLocal变量可以是非静态的, 因为切面类也是一个单例的bean, 所有线程也是共享同一个ThreadLocal变量.

在操作完成后, 记得对ThreadLocal变量做remove操作防止内存泄露. 类似C语言的free.

2.5. 连接点相关参数和变量记录(重点)

记录日志, 重点实际上是通过获取连接点, 记录一下连接点方法执行后的一些变量和参数, 再拼接成需要的日志形式. 对连接点的操作和反射的操作很类似, 多了方法入参值(如果有)和方法返回结果(如果有).

拿后置通知举例, 我们可以拿到连接点中指定的注解或者方法入参, 还有方法参数表写着的参数名称.

  • 获取自定义注解(重点)
	// @GetLog为自定义注解. 可以获取到, 基本只要你切这个注解你一定拿的到这个注解.   
	public GetLog getSystemLog(JoinPoint joinPoint) {
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        // 获取切入点所在的方法
        Method method = signature.getMethod();
        return method.getAnnotation(GetLog.class);
    }
  • 获取方法参数表和实际入参值(重点)
        MethodSignature methodSignature = (MethodSignature) joinPoint.getSignature(); // 方法签名
        String[] names = methodSignature.getParameterNames(); // 从签名获取参数名字
        Object[] args = joinPoint.getArgs(); // 获取实际入参值

这两个重点对后文难点有至关重要的作用.

3. Logback配置文件的基本配置

SpringBoot 2.x已经集成了Logback, 如果不在resources目录下放logback-spring.xml或者logback.xml文件的话, 它会有一个默认的配置.

实现基于Logback记录日志到数据库, 我们少不了编写配置文件这一步. 针对数据库的Appender后文将会提及.

下面是logback-spring.xml的编写模板以及各个配置项的解析.

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="true" scanPeriod="60 seconds" debug="false" packingData="false">
<!--
在配置文件中配置：
#单个日志最大大小
size_max=500MB
#日志保存天数
days_max=365
-->
    <springProperty name="size_max" source="size_max"/>
    <springProperty name="days_max" source="days_max"/>

<!--
变量定义:低版本可以通过<property> 来定义，1.0.7版本后可以通过<variable>等同于<property>，二者一样
使用： ${变量名}
指定默认值：以:- 分隔 ${name:-value}
-->
    <variable name="LOG_HOME" value=".\logs"/>
    <variable name="CONSOLE_LOG_PATTERN" value="%highlight(%d{yyyy-MM-dd HH:mm:ss}) | %-5level | %blue(%thread) | %blue(%file:%line) | %green(%logger) >> %cyan(%msg%n)" />
    <variable name="FILE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} | %-5level | %thread | %file:%line | %logger : %msg%n" />
    <variable name="druid.driverClassName" value="com.mysql.cj.jdbc.Driver" />
    <variable name="druid.url" value="你的数据库地址" />
    <variable name="druid.username" value="你的账户" />
    <variable name="druid.password" value="你的密码" />

    <!-- 配置 Logback 的 DB Appender appender的class指的就是后文要写的自定义DbAppender-->
    <appender name="DB" class="com.myPack.log.MyDbAppender">
        <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
            <dataSource class="com.alibaba.druid.pool.DruidDataSource">
                <driverClassName>${druid.driverClassName}</driverClassName>
                <url>${druid.url}</url>
                <username>${druid.username}</username>
                <password>${druid.password}</password>
                <!-- 其他配置项，如初始连接数、最大连接数等 -->
                <initialSize>5</initialSize>
                <maxActive>20</maxActive>
                <minIdle>5</minIdle>
                <maxWait>60000</maxWait>
            </dataSource>
        </connectionSource>
    </appender>


<!--     控制台输出-->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>


    <!--输出到日志滚动文件-->
    <!--FileAppender将日志事件追加到指定日志文件中-->
    <!--使用RollingFileAppender，继承继承自FileAppender，支持日志分片和历史日志的自动删除-->
    <!--
    RollingFileAppender执行流程：
        1、日志始终追加写入指定的日志文件中，若文件不存在则自动创建
        2、按rollingPolicy配置的策略，当满足策略时，自动将file重命名为rollingPolicy中指定的归档日志文件名，生成历史归档日志，如 /temp/test.2023-04-12.log，并对归档日志进行压缩 和 过期日志删除。
        3、循环 1-2
    -->
    <appender name="infoLog" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--日志文件的路径-->
        <File>${logback.logDir}/info.log</File>
        <!--append：true | false，是否以追加的方式写到日志文件，默认true-->
        <append>true</append>
        <!--encoder：指定输出日志格式化和字符集-->
        <encoder>
            <charset>UTF-8</charset>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
        <!--prudent:安全模式，性能较差，一般不开启，默认false-->
        <prudent>false</prudent>
        <!--滚动（归档）策略， TimeBasedRollingPolicy：按照时间滚动（归档），超出指定时间范围的日志自动删除；
                            SizeAndTimeBasedRollingPolicy：按时间和文件大小滚动（归档）
        -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!--文件路径,定义了日志的切分方式——把每一天的日志归档到一个文件中-->
            <FileNamePattern>${logback.logDir}/arch/info/info.%d{yyyy-MM-dd}.%i.log</FileNamePattern>

            <!--日志保留时长（天）-->
            <maxHistory>${days_max}</maxHistory>

            <!--单个日志文件最大容量-->
            <maxFileSize>${size_max}</maxFileSize>

            <!--maxHistory内日志最大容量，到了这个值，就会删除旧的日志-->
            <!--<totalSizeCap>1GB</totalSizeCap>-->

            <!--cleanHistoryOnStart：项目启动时是否清理归档日志，默认false-->
            <cleanHistoryOnStart>false</cleanHistoryOnStart>
            
        </rollingPolicy>
    </appender>


    <!--将warn、error日志单独存储一份    -->
    <appender name="errorLog" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--过滤器，过滤满足条件或者不满足条件的日志
            LevelFilter：级别过滤器，匹配指定的日志级别
            ThresholdFilter：阈值过滤器，匹配等于或高于指定级别的日志
        -->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>WARN</level>
        </filter>
        <!--日志名称，如果没有File 属性，那么只会使用FileNamePattern的文件路径规则
            如果同时有<File>和<FileNamePattern>，那么当天日志是<File>，明天会自动把今天
            的日志改名为今天的日期。即，<File> 的日志都是当天的。
        -->
        <File>${logback.logDir}/error.log</File>
        <!--滚动策略，按照时间滚动 TimeBasedRollingPolicy-->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!--文件路径,定义了日志的切分方式——把每一天的日志归档到一个文件中,以防止日志填满整个磁盘空间-->
            <FileNamePattern>${logback.logDir}/arch/error/error.%d{yyyy-MM-dd}.%i.log</FileNamePattern>
            <!-- 单个日志文件最多 100MB -->
            <maxFileSize>${size_max}</maxFileSize>
            <!--只保留最近30天的日志-->
            <maxHistory>${days_max}</maxHistory>
            <!--用来指定日志文件的上限大小，那么到了这个值，就会删除旧的日志-->
            <!--<totalSizeCap>1GB</totalSizeCap>-->
        </rollingPolicy>
        <!--日志输出编码格式化-->
        <encoder>
            <charset>UTF-8</charset>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>


    <!--使用<logger>标签指定com.myPack.controller包内的日志在控制台输出的级别为warn-->
    <!--配置additivity="false"，否则<root>中也配置了<appender-ref ref="console"/>，会重复输出日志。-->
    <logger name="com.sw.controller" level="warn" additivity="false">
        <appender-ref ref="console"/>
    </logger>

    <!--整个项目下, 前面logger没有指定的包的日志由root logger处理. 建议在<root>中引用所有<appender>,
root logger的日志信息会输出到下方的appender-->
    <root level="info">
        <appender-ref ref="console"/>
        <appender-ref ref="infoLog"/>
        <appender-ref ref="errorLog"/>
    </root>

</configuration>

引用自: logback.xml配置模板（包含全部配置及注释，直接复制粘贴后按照需要稍作修改即可）_logback.xml配置文件模板-CSDN博客

4. 自定义Logback DbAppender

Logback里面的appender到底是干什么的？

在 Logback 中，appender 是负责将日志事件（log events）输出到特定目标的组件。每个 appender 都有特定的职责，例如将日志输出到控制台、文件、数据库、远程服务器等

在这一步, 我们着重说如何写一个自定义DbAppender, 用与满足我们自己的实际日志记录需求.

此处对自定义DbAppender的讲解和源码分析, 贴一篇非常好的博客.

Logback输出日志到自定义MySQL数据库（重写DBAppender）_logback日志输出到mysql数据库-CSDN博客

整个自定义的讲解只会针对对一些重点需要我们关注的方法实现, 想了解更详细的源码分析和流程分析请参考这篇博客.

4.1. Appender概述

一个用于将日志插入到数据库的DbAppender, 需要继承ch.qos.logback.core.db包下的DBAppenderBase, 指定DBAppender的泛型为ILoggingEvent. DBAppenderBase是一个抽象类, 需要我们实现下面的方法.

 protected void subAppend(ILoggingEvent event, Connection connection, PreparedStatement insertStatement) throws Throwable;

这个方法主要用于进行日志插入到数据库表的操作, 是核心方法. 当记录日志的信息丢到我们这个自定义appender的时候, 这个方法会被调用, 用于执行insertStatement, 也就是执行sql语句进行插入. 而日志信息记录在入参event中, 需要我们去解析.

// 这个方法用来在插入日志后执行其他操作，比如获取生成的主键
protected void secondarySubAppend(ILoggingEvent event, Connection connection, long eventId)

按照实际业务需要记录这个eventId.

protected Method getGeneratedKeysMethod() // 用于返回获取主键的方法

这个方法有现成的.

getGeneratedKeysMethod = PreparedStatement.class.getMethod("getGeneratedKeys", (Class<?>[]) null);

protected String getInsertSQL() // 用于返回期望使用的sql语句

期望使用的sql语句应该按照自己的日志记录需要, 事先写死在这个类里面, 例如使用静态成员变量去记录.(业务员需要指你想记录什么信息, 分开什么样的字段去记录, 比如下面的例子) 这个语句应该是符合PreparedStatement类型的字符串, 即用问号指代实际要拼接进sql的参数. 然后直接在这个方法中返回即可.

INSERT_SQL = "INSERT INTO t_log (log_level, log_msg, log_type, operation, request_uri, http_method, request_args, duration, result, exception) VALUES " +
        "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?)";
    @Override
    protected String getInsertSQL() {
        return INSERT_SQL;
    }

4.2. subAppend方法

前面提到, 我们有了预期使用的insert sql语句, logback在背后利用这个写死的sql构建了PreparedStatement类型的变量insertStatement, 作为参数传入subAppend方法. 而event变量又记录着日志信息, 这个方法的目的在此刻也明确了, 就是解析event, 得到insertStatement需要的参数并且进行拼接, 拼接完毕执行sql, 完成日志记录

4.2.1. event解析

要想解析, 先看看这里有什么信息给我们解析. 启动debug, 查看一下在切面的后置通知中使用log.info(message)方法记录日志后, 传入到subAppend方法的event包含什么信息.
请添加图片描述

  • 线程名字
  • 记录日志的类(loggerName) 一般统一在切面类去记录日志, loggerName也就是切面类的全限定名.
  • level 日志级别
  • message/formattedMessage 使用log.info(message)等方法记录日志时传入的message

可以知道, 实际上的日志信息其实需要我们在log.info()方法的时候, 传入自己设置好格式和字段顺序的字符串, 用于分开解析.

比如在这个项目, 切面类在后置通知里会处理连接点的入参, 返回结果, 请求路径等信息, 然后按照一定的顺序和分隔符|去分开这些信息, 这样在解析message时就方便了.

多加一个msgToLog方法, 用于解析event. 其中, Log类对应项目中专门记录日志的表. 其中, 根据自己如何处理连接点的各种参数, 依照格式和顺序去使用String类提供的split方法, 一个个读取, 然后构造一个自定义Log对象.

private Log msgToLog(ILoggingEvent event) {
    String formattedMessage = event.getFormattedMessage();
    if (formattedMessage.contains("|##") && event.getLevel().toString().equals("ERROR")) {// 处理ERROR级别的报错日志, 获取到报错信息.
        String[] split = formattedMessage.split("\\|");
        return Log.builder()
                .logLevel(event.getLevel().toString())  	 // 日志级别
                .logMsg(formattedMessage)					// 原始日志信息
                .logType(split[0])										// 日志类型(项目业务需求)
                .operation(split[1])								   // 操作(项目业务需求, 结合后文的解析自定义注解获取)
                .requestUri(split[2])								   // 请求接口路径
                .httpMethod(split[3])      					        // 请求http方法
                .requestArgs(split[4])								 // 入参
                .result("exception:" + split[5] + ", msg: " + split[6]) // 返回结果
                .exception(split[7])								  // 实际报错
                .build();
    }else {
        String[] split = formattedMessage.split("\\|");
        return Log.builder()
                .logLevel(event.getLevel().toString())
                .logMsg(formattedMessage)
                .logType(split[0])
                .operation(split[1])
                .requestUri(split[2])
                .httpMethod(split[3])
                .requestArgs(split[4])
                .duration(Long.parseLong(split[5].trim())) // 方法执行时间
                .result(split[6])
                .exception("no exception")
                .build();
    }
}

在subAppend方法中调用msgToLog方法解析event, 得到一个Log对象, 正好就和数据库的日志表对应.

请添加图片描述

整个subAppend方法就好写出来了, 贴代码.

4.3. MyDbAppender.java

public class MyDbAppender extends DBAppenderBase<ILoggingEvent> {
    /**
     * 插入语句
     */
    protected static final String INSERT_SQL;
    /**
     * 用于在执行插入语句后获取生成的主键
     */
    protected static final Method GET_GENERATED_KEYS_METHOD;

    /**
     * 日志表中的字段顺序, 用于拼接PreparedStatement
     */
    static final int LOG_LEVEL = 1;
    static final int LOG_MSG = 2;
    static final int LOG_TYPE = 3;
    static final int OPERATION = 4;
    static final int REQUEST_URI = 5;
    static final int HTTP_METHOD = 6;
    static final int REQUEST_ARGS = 7;
    static final int DURATION = 8;
    static final int RESULT = 9;
    static final int EXCEPTION = 10;

    static {
        Method getGeneratedKeysMethod;
        try {
            getGeneratedKeysMethod = PreparedStatement.class.getMethod("getGeneratedKeys", (Class<?>[]) null);
        } catch (Exception ex) {
            getGeneratedKeysMethod = null;
        }
        GET_GENERATED_KEYS_METHOD = getGeneratedKeysMethod;
        //language=MySQL
        INSERT_SQL = "INSERT INTO t_log (log_level, log_msg, log_type, operation, request_uri, http_method, request_args, duration, result, exception) VALUES " +
                "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?)";
    }

    /**
     * subAppend 方法用于实际执行日志的插入操作。它从传入的 ILoggingEvent 中提取信息，创建 Log 对象，并使用预编译的语句将日志信息插入数据库
     */
    @Override
    protected void subAppend(ILoggingEvent event, Connection connection, PreparedStatement insertStatement) throws Throwable {
        // 解析出自定义日志类型，以及存放日志类型
        Log log = msgToLog(event);
        // 创建一个时区为 GMT+8 的时区偏移量
        ZoneOffset offset = ZoneOffset.ofHours(8);

        // 获取当前时间，并转换为 GMT+8 时区
        LocalDateTime localDateTime = LocalDateTime.now();
        OffsetDateTime offsetDateTime = OffsetDateTime.of(localDateTime, offset);

        // 将 OffsetDateTime 转换为数据库所需的格式
        Timestamp timestamp = Timestamp.valueOf(offsetDateTime.atZoneSameInstant(ZoneOffset.UTC).toLocalDateTime());

        log.setLogCreateTime(timestamp.toLocalDateTime());

        // 预编译语句装载
        insertStatement.setString(LOG_LEVEL, log.getLogLevel());
        insertStatement.setString(LOG_MSG, log.getLogMsg());
        insertStatement.setString(LOG_TYPE, log.getLogType());
        insertStatement.setString(OPERATION, log.getOperation());
        insertStatement.setString(REQUEST_URI, log.getRequestUri());
        insertStatement.setString(HTTP_METHOD, log.getHttpMethod());
        insertStatement.setString(REQUEST_ARGS, log.getRequestArgs());
        insertStatement.setLong(DURATION, log.getDuration());
        insertStatement.setString(RESULT, log.getResult());
        insertStatement.setString(EXCEPTION, log.getException());

        // 执行插入日志语句
        int updateCount = insertStatement.executeUpdate();
        if (updateCount != 1) {
            addWarn("Failed to insert loggingEvent");
        }
    }

    /**
     * secondarySubAppend 方法用于在插入日志后执行其他操作，比如获取生成的主键
     */
    @Override
    protected void secondarySubAppend(ILoggingEvent event, Connection connection, long eventId) {
    }

    /**
     * getGeneratedKeysMethod 方法用于获取生成的主键
     */
    @Override
    protected Method getGeneratedKeysMethod() {
        return GET_GENERATED_KEYS_METHOD;
    }

    /**
     * getInsertSQL 方法用于获取插入语句
     */
    @Override
    protected String getInsertSQL() {
        return INSERT_SQL;
    }
    
    private Log msgToLog(ILoggingEvent event) {
        // 上文有...
	}
}

5. 切自定义注解实现记录自定义格式日志

当我们切点设置为自定义注解时, 我们就能控制哪一些方法我们需要走切面的日志记录.

下面将讲解这个项目的自定义注解处理思路, 不为唯一的方案.

5.1. 自定义注解

@Target({ElementType.PARAMETER, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface GetLog {
    String description() default ""; // 日志操作描述
    String requestParam() default "no request parameter"; // 入参, 使用#{param}读取实际入参值
}

先在这里说明整个注解在最后的用法和效果

在任意方法上加这个注解, 方法将会被标记为某个切点的一个连接点. 在这个切点的后置通知中, 会把description拿到, 把requestParam解析为实际的格式. 拼接为:

操作人(从上下文拿到) + description -> 日志表中的operation字段

requestParam -> 解析后放入日志表中的request_args字段

结合在后置通知从连接点拿到的信息, 拼接日志信息, 使用log.info()或者log.error()等方法记录日志, 输出到DbAppender, 完成日志记录. 由于只有走切面类的log方法, 日志信息格式才满足DbAppender的格式要求, 所以只有加上自定义注解方法被切后的后置通知内的log.info(message) 或者 log.error(message)会被记录到数据库, 其他的系统日志不满足格式要求, 不会进入到数据库, 只会在文件和控制台输出.

其中requestParam的处理为难点, 实际上可以不加. 后文会详细介绍这个项目在这个字段上做的事情, 非常具有技术性.

5.2. 切面类

定义一个切面类.

@Aspect // 切面
@Component // 被IOC容器管理
@Slf4j // logger对象
public class SystemLogAspect {
    
        private static final ThreadLocal<Date> beginTimeThreadLocal = new NamedThreadLocal<>("ThreadLocal beginTime"); // 用于统计方法耗时
    
        @Autowired(required = false)
    private HttpServletRequest request; // 用于获取每一个请求的请求路径, 每个请求都会单独注入, 所以可以正确获取, 没有收到切面类的单例模式的影响(虽然不知道怎么实现的...)
    
    //...
}
5.2.1. 切点定义
@Pointcut("@annotation(com.yourPack.log.GetLog)")
public void controllerAspect() {
}

表达式表明所有带有GetLog注解的方法都被标记为切点controllerAspect()下的连接点.

5.2.2. 前置通知
@Before("controllerAspect()")
public void doBefore() {
    //线程绑定变量（该数据只有当前请求的线程可见）
    Date beginTime = new Date();
    beginTimeThreadLocal.set(beginTime);
}

记录目标方法执行前的时间.

5.2.3. 后置通知
@AfterReturning(value = "controllerAspect()", returning = "result")
public void after(JoinPoint joinPoint, Object result) {
    long endTime = System.currentTimeMillis();
    try {
        GetLog systemLog = getSystemLog(joinPoint); // 通过方法签名获取注解对象
        Object logParams = getLogParams(joinPoint, systemLog); // 解析注解, 获取格式化后的入参
        String logType = getLogType; // 本项目业务
        String description = systemLog.description(); // 注解中description值
        //如果是获取不到参数
        if (logParams == null) {
            logParams = "无参数";
        }

        //请求开始时间
        long beginTime = beginTimeThreadLocal.get().getTime();
        //请求耗时
        long logElapsedTime = endTime - beginTime;
        String msg = LogUtil.buildLogMsg(logType,
                description,
                request.getRequestURI(),
                request.getMethod(),
                logParams.toString(),
                (int) logElapsedTime,
                result);// 拼接格式化日志信息
        log.info(msg); // logger拿到日志信息, 分发给appender
        beginTimeThreadLocal.remove(); // 清除线程变量.
    } catch (Exception e) {
        log.error("AOP后置通知异常", e);
    }
}

    public GetLog getSystemLog(JoinPoint joinPoint) {
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        // 获取切入点所在的方法
        Method method = signature.getMethod();
        return method.getAnnotation(GetLog.class);
    }

5.3. 使用举例

@PostMapping("/login")
@GetLog(description = "管理员登陆", requestParam = "账号：#{loginUserDto.userName}， 密码：#{loginUserDto.userPass}")
public ResultWeb<?> login(@RequestBody LoginUserDto loginUserDto) {
    UserDto user = new UserDto(loginUserDto.getUserName(), loginUserDto.getUserPass());
    return userService.platformLogin(user);
}

这是项目中的登陆接口. 方法加上了@GetLog注解, 表明方法被切, 方法执行完后, 方法的入参, 返回结果, 请求路径等信息都会被后置通知拿到. 后面则是解析, 记录, 插数据库了.

到这里实际上已经把整套流程走完了, 不需要入参格式化的话只需要去掉注解的requestParam字段, 可以通过连接点获取原始的入参数据, 按照自己项目的需求操作即可.

6. Mybatis对于占位符的解析搬运到记录自定义日志上

这部分是如何实现格式化入参信息.

在5.3节的最后, 自定义注解中出现了一个requestParam = "账号：#{loginUserDto.userName}， 密码：#{loginUserDto.userPass}", 这个就是对入参的格式化.

读者如果能认真读到这里了, 估计也明白mybatis的用法. 这里是不是很熟悉?

// 一个mybatis框架中dao层的接口写法
@Select("select * from teachers where phoneNumber = #{phoneNumber}")
 Teacher getTeacherByPhoneNumber(@Param("phoneNumber") String phoneNumber);

这不就是mybatis中的占位符写法吗? 是的, 在这里这个占位符占的是实际对应的入参值.

自定义注解的这个值会在后置通知中被拿到, 此时也有实际入参值, 现在就是参照mybatis的方法解析占位符并且拼接实际值.

这部分内容在后面的文章单独会介绍一次, 会带着mybatis简单实现的一部分内容->解析占位符部分.

感谢看到这里.

# 数据库 # spring # logback
Logo
DAMO开发者矩阵

DAMO开发者矩阵，由阿里巴巴达摩院和中国互联网协会联合发起，致力于探讨最前沿的技术趋势与应用成果，搭建高质量的交流与分享平台，推动技术创新与产业应用链接，围绕“人工智能与新型计算”构建开放共享的开发者生态。

更多推荐

cover

KingbaseES数据库：医疗信创潮涌沅江，国产化信创打造医疗新质生产力

avatar DAMO开发者矩阵
cover

告别迁移焦虑：金仓KDMS V4带你轻松搞定数据库国产化替代

avatar DAMO开发者矩阵
cover

KingbaseES数据库在常德二院全栈国产化信创中产生新质生产力,医疗信创的部署如何实现，如何操作？

avatar DAMO开发者矩阵