《SpringBoot项目实战》第三篇—留下用户调用接口的痕迹

系列文章导航
第一篇—接口参数的一些弯弯绕绕
第二篇—接口用户上下文的设计与实现
第三篇—留下用户调用接口的痕迹
第四篇—接口的权限控制
第五篇—接口发生异常如何统一处理

本文参考项目源码地址：summo-springboot-interface-demo

前言

大家好！我是sum墨，一个一线的底层码农，平时喜欢研究和思考一些技术相关的问题并整理成文，限于本人水平，如果文章和代码有表述不当之处，还请不吝赐教。

作为一名从业已达六年的老码农，我的工作主要是开发后端Java业务系统，包括各种管理后台和小程序等。在这些项目中，我设计过单/多租户体系系统，对接过许多开放平台，也搞过消息中心这类较为复杂的应用，但幸运的是，我至今还没有遇到过线上系统由于代码崩溃导致资损的情况。这其中的原因有三点：一是业务系统本身并不复杂；二是我一直遵循某大厂代码规约，在开发过程中尽可能按规约编写代码；三是经过多年的开发经验积累，我成为了一名熟练工，掌握了一些实用的技巧。

接口设计是整个系统设计中非常重要的一环，其中包括限流、权限、入参出参、切面等方面。设计一个好的接口可以帮助我们省去很多不必要的麻烦，从而提升整个系统的稳定性和可扩展性。作为接口设计经验分享的第三篇，我想分享一下如何在用户使用过程中留下操作痕迹。在实际开发中，我会采取一些手段来记录用户操作，例如使用日志记录用户行为，或者在数据库中保存用户操作记录。这些痕迹可以帮助我们快速定位和解决问题，同时也可以为后续数据分析和优化提供有价值的参考。

方法一、将接口的参数和结果打印在日志文件中

日志文件是我们记录用户使用痕迹的第一个地方，我之前写过一篇SpringBoot项目如何配置logback.xml的文章来实现系统日志输出，有兴趣的同学可以去看看。
这里我主要讲一下怎么方便将所有接口的出入参打印出来。

1、使用aop监控接口

依赖如下

<!-- aspectj -->
<dependency>
  <groupId>org.aspectj</groupId>
  <artifactId>aspectjweaver</artifactId>
  <version>1.9.5</version>
</dependency>

如果有同学不知道aspectj是啥的，可以看我这篇文章SpringBoot整合aspectj实现面向切面编程(即AOP)

关键代码如下

package com.summo.aspect;

import java.util.Objects;

import javax.servlet.http.HttpServletRequest;

import com.alibaba.druid.util.StringUtils;

import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestAttributes;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

@Aspect
@Component
@Slf4j
public class ControllerLoggingAspect {

    /**
     * 拦截所有controller包下的方法
     */
    @Pointcut("execution(* com.summo.controller..*.*(..))")
    private void controllerMethod() {

    }

    @Around("controllerMethod()")
    public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();
        //获取本次接口的唯一码
        String token = java.util.UUID.randomUUID().toString().replaceAll("-", "").toUpperCase();
        MDC.put("requestId", token);

        //获取HttpServletRequest
        RequestAttributes ra = RequestContextHolder.getRequestAttributes();
        ServletRequestAttributes sra = (ServletRequestAttributes)ra;
        HttpServletRequest request = sra.getRequest();

        // 获取请求相关信息
        String url = request.getRequestURL().toString();
        String method = request.getMethod();
        String uri = request.getRequestURI();
        String params = request.getQueryString();
        if (StringUtils.isEmpty(params) && StringUtils.equals("POST", method)) {
            if (Objects.nonNull(joinPoint.getArgs())) {
                for (Object arg : joinPoint.getArgs()) {
                    params += arg;
                }
            }
        }
        // 获取调用方法相信
        Signature signature = joinPoint.getSignature();
        String className = signature.getDeclaringTypeName();
        String methodName = signature.getName();
        log.info("@http请求开始, {}#{}() URI: {}, method: {}, URL: {}, params: {}",
            className, methodName, uri, method, url, params);
        //result的值就是被拦截方法的返回值
        try {
            //proceed方法是调用实际所拦截的controller中的方法，这里的result为调用方法后的返回值
            Object result = joinPoint.proceed();
            long endTime = System.currentTimeMillis();
            //定义请求结束时的返回数据，包括调用时间、返回值结果等
            log.info("@http请求结束, {}#{}(), URI: {}, method: {}, URL: {}, time: {}ms ",
                className, methodName, uri, method, url, (endTime - startTime));

            return result;
        } catch (Exception e) {
            long endTime = System.currentTimeMillis();
            log.error("@http请求出错, {}#{}(), URI: {}, method: {}, URL: {}, time: {}ms",
                className, methodName, uri, method, url, (endTime - startTime), e);
            throw e;
        } finally {
            MDC.remove("requestId");
        }
    }
}

2、增加requestId

由于接口的调用都是异步的，所以一旦QPS上来，那么接口的调用就会很混乱，不加一个标识的话，就不知道哪个返回值属于那个请求的了。
这个时候我们则需要加一个requestId(或者叫traceId)用来标识一个请求。

也即这段代码

//获取本次接口的唯一码
String token = java.util.UUID.randomUUID().toString().replaceAll("-", "").toUpperCase();
MDC.put("requestId", token);

... ... 
MDC.remove("requestId");

同时logback.xml中也需要加一下requestId的打印，在logback.xml中可以使用%X{requestId}获取到MDC中添加的遍历。
完整的logback.xml配置文件如下：

<configuration>
    <!-- 默认的一些配置 -->
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <!-- 定义应用名称，区分应用 -->
    <property name="APP_NAME" value="monitor-test"/>
    <!-- 定义日志文件的输出路径 -->
    <property name="LOG_PATH" value="${user.home}/logs/${APP_NAME}"/>
    <!-- 定义日志文件名称和路径 -->
    <property name="LOG_FILE" value="${LOG_PATH}/application.log"/>
    <!-- 定义警告级别日志文件名称和路径 -->
    <property name="WARN_LOG_FILE" value="${LOG_PATH}/warn.log"/>
    <!-- 定义错误级别日志文件名称和路径 -->
    <property name="ERROR_LOG_FILE" value="${LOG_PATH}/error.log"/>

    <!-- 自定义控制台打印格式 -->
    <property name="FILE_LOG_PATTERN" value="%green(%d{yyyy-MM-dd HH:mm:ss.SSS}) [%blue(requestId: %X{requestId})] [%highlight(%thread)] ${PID:- } %logger{36} %-5level - %msg%n"/>

    <!-- 将日志滚动输出到application.log文件中 -->
    <appender name="APPLICATION"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 输出文件目的地 -->
        <file>${LOG_FILE}</file>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
        <!-- 设置 RollingPolicy 属性，用于配置文件大小限制，保留天数、文件名格式 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- 文件命名格式 -->
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 文件保留最大天数 -->
            <maxHistory>7</maxHistory>
            <!-- 文件大小限制 -->
            <maxFileSize>50MB</maxFileSize>
            <!-- 文件总大小 -->
            <totalSizeCap>500MB</totalSizeCap>
        </rollingPolicy>
    </appender>

    <!-- 摘取出WARN级别日志输出到warn.log中 -->
    <appender name="WARN" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${WARN_LOG_FILE}</file>
        <encoder>
            <!-- 使用默认的输出格式打印 -->
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
        <!-- 设置 RollingPolicy 属性，用于配置文件大小限制，保留天数、文件名格式 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- 文件命名格式 -->
            <fileNamePattern>${LOG_PATH}/warn.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 文件保留最大天数 -->
            <maxHistory>7</maxHistory>
            <!-- 文件大小限制 -->
            <maxFileSize>50MB</maxFileSize>
            <!-- 文件总大小 -->
            <totalSizeCap>500MB</totalSizeCap>
        </rollingPolicy>
        <!-- 日志过滤器，将WARN相关日志过滤出来 -->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>WARN</level>
        </filter>
    </appender>

    <!-- 摘取出ERROR级别日志输出到error.log中 -->
    <appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${ERROR_LOG_FILE}</file>
        <encoder>
            <!-- 使用默认的输出格式打印 -->
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
        <!-- 设置 RollingPolicy 属性，用于配置文件大小限制，保留天数、文件名格式 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- 文件命名格式 -->
            <fileNamePattern>${LOG_PATH}/error.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 文件保留最大天数 -->
            <maxHistory>7</maxHistory>
            <!-- 文件大小限制 -->
            <maxFileSize>50MB</maxFileSize>
            <!-- 文件总大小 -->
            <totalSizeCap>500MB</totalSizeCap>
        </rollingPolicy>
        <!-- 日志过滤器，将ERROR相关日志过滤出来 -->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

    <!-- 配置控制台输出 -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>


    <!-- 配置输出级别 -->
    <root level="INFO">
        <!-- 加入控制台输出 -->
        <appender-ref ref="CONSOLE"/>
        <!-- 加入APPLICATION输出 -->
        <appender-ref ref="APPLICATION"/>
        <!-- 加入WARN日志输出 -->
        <appender-ref ref="WARN"/>
        <!-- 加入ERROR日志输出 -->
        <appender-ref ref="ERROR"/>
    </root>
</configuration>

3、效果如下图

4、接口监控遇到的一些坑

返回值数据量很大会刷屏，尽量不要打印返回值。
文件上传接口会直接挂掉，所以上传的接口一般不会加入监控。

方法二、将风险高的操作保存到数据库中

虽然方法一能够记录每个接口的日志，但这些日志只存在于服务器上，并且有大小和时间限制，到期后就会消失。这种做法对所有请求或操作都一视同仁，不会对风险较高的请求进行特殊处理。为了解决危险操作带来的风险，我们需要将其持久化，以便在出现问题时能够快速找到原因。最常见的做法是将风险高的操作保存到数据库中。
实现原理还是使用方法一种的切面，不过这里使用的是注解切面，具体做法请见下文。

1、新建一张log表，存储风险操作

表结构如下：

建表语句我也贴出来

SET NAMES utf8mb4;
SET FOREIGN_KEY_CHECKS = 0;

-- ----------------------------
-- Table structure for user_oper_log
-- ----------------------------
DROP TABLE IF EXISTS `user_oper_log`;
CREATE TABLE `user_oper_log` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT COMMENT '物理主键',
  `operation` varchar(64) DEFAULT NULL COMMENT '操作内容',
  `time` bigint DEFAULT NULL COMMENT '耗时',
  `method` text COMMENT '操作方法',
  `params` text COMMENT '参数内容',
  `ip` varchar(64) DEFAULT NULL COMMENT 'IP',
  `location` varchar(64) DEFAULT NULL COMMENT '操作地点',
  `response_code` varchar(32) DEFAULT NULL COMMENT '应答码',
  `response_text` text COMMENT '应答内容',
  `gmt_create` datetime DEFAULT NULL COMMENT '创建时间',
  `gmt_modified` datetime DEFAULT NULL COMMENT '更新时间',
  `creator_id` bigint DEFAULT NULL COMMENT '创建人',
  `modifier_id` bigint DEFAULT NULL COMMENT '更新人',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8mb4  COMMENT='用户操作日志表';

SET FOREIGN_KEY_CHECKS = 1;

核心字段为操作方法、参数内容、IP、操作地点、应答码、应答内容、创建人这些，其中IP和操作地址这两个是推算的，不一定很准。这些字段也不是非常全面，如果大家还有自己想记录的字段信息也可以加进来。

2、新建@Log注解和切面处理类LogAspect

注解类

package com.summo.log;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Log {
    /**
     * 接口功能描述
     *
     * @return
     */
    String methodDesc() default "";
}

切面处理类

package com.summo.log;

import java.io.Serializable;
import java.lang.reflect.Method;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Calendar;
import java.util.List;
import java.util.Map;
import java.util.Set;

import javax.servlet.http.HttpServletRequest;

import com.alibaba.fastjson.JSONObject;

import com.summo.entity.UserOperInfoDO;
import com.summo.repository.UserOperInfoRepository;
import com.summo.util.HttpContextUtil;
import com.summo.util.IPUtil;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.core.LocalVariableTableParameterNameDiscoverer;
import org.springframework.stereotype.Component;
import org.springframework.web.multipart.MultipartFile;

@Slf4j
@Aspect
@Component
public class LogAspect {

    @Autowired
    private UserOperInfoRepository userOperInfoRepository;

    @Pointcut("@annotation(com.summo.log.Log)")
    public void pointcut() {
        // do nothing
    }

    @Around("pointcut()")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
        Object result = null;
        //默认操作对象为-1L
        MethodSignature signature = (MethodSignature)joinPoint.getSignature();
        Method method = signature.getMethod();
        Log logAnnotation = method.getAnnotation(Log.class);
        UserOperInfoDO log = new UserOperInfoDO();
        if (logAnnotation != null) {
            // 注解上的描述
            log.setOperation(logAnnotation.methodDesc());
        }
        // 请求的类名
        String className = joinPoint.getTarget().getClass().getName();
        // 请求的方法名
        String methodName = signature.getName();
        log.setMethod(className + "." + methodName + "()");
        // 请求的方法参数值
        Object[] args = joinPoint.getArgs();
        // 请求的方法参数名称
        LocalVariableTableParameterNameDiscoverer u = new LocalVariableTableParameterNameDiscoverer();
        String[] paramNames = u.getParameterNames(method);
        if (args != null && paramNames != null) {
            StringBuilder params = new StringBuilder();
            params = handleParams(params, args, Arrays.asList(paramNames));
            log.setParams(params.toString());
        }
        log.setGmtCreate(Calendar.getInstance().getTime());
        long beginTime = System.currentTimeMillis();
        // 执行方法
        result = joinPoint.proceed();
        // 执行时长(毫秒)
        long time = System.currentTimeMillis() - beginTime;
        HttpServletRequest request = HttpContextUtil.getHttpServletRequest();
        // 设置 IP 地址
        String ip = IPUtil.getIpAddr(request);
        log.setIp(ip);
        log.setTime(time);

        //保存操作记录到数据库中
        userOperInfoRepository.save(log);
        return result;
    }

    /**
     * 参数打印合理化
     *
     * @param params     参数字符串
     * @param args       参数列表
     * @param paramNames 参数名
     * @return
     */
    private StringBuilder handleParams(StringBuilder params, Object[] args, List paramNames) {
        for (int i = 0; i < args.length; i++) {
            if (args[i] instanceof Map) {
                Set set = ((Map)args[i]).keySet();
                List<Object> list = new ArrayList<>();
                List<Object> paramList = new ArrayList<>();
                for (Object key : set) {
                    list.add(((Map)args[i]).get(key));
                    paramList.add(key);
                }
                return handleParams(params, list.toArray(), paramList);
            } else {
                if (args[i] instanceof Serializable) {
                    Class<?> aClass = args[i].getClass();
                    try {
                        aClass.getDeclaredMethod("toString", new Class[] {null});
                        // 如果不抛出 NoSuchMethodException 异常则存在 toString 方法 ，安全的 writeValueAsString ，否则 走 Object的
                        // toString方法
                        params.append(" ").append(paramNames.get(i)).append(": ").append(
                            JSONObject.toJSONString(args[i]));
                    } catch (NoSuchMethodException e) {
                        params.append(" ").append(paramNames.get(i)).append(": ").append(
                            JSONObject.toJSONString(args[i].toString()));
                    }
                } else if (args[i] instanceof MultipartFile) {
                    MultipartFile file = (MultipartFile)args[i];
                    params.append(" ").append(paramNames.get(i)).append(": ").append(file.getName());
                } else {
                    params.append(" ").append(paramNames.get(i)).append(": ").append(args[i]);
                }
            }
        }
        return params;
    }
}

3、使用方法

在需要监控的接口方法上加上@Log注解

@PostMapping("/saveRel")
@Log(methodDesc = "添加记录")
public Boolean saveRel(@RequestBody SaveRelReq saveRelReq) {
    return userRoleRelService.saveRel(saveRelReq);
}

@DeleteMapping("/delRel")
@Log(methodDesc = "删除记录")
public Boolean delRel(Long relId) {
    return userRoleRelService.delRel(relId);
}

调用一下测试功能

数据库中保存的记录

这里可以看到已经有记录保存在数据库中了，包括两次添加操作、一次删除操作，并且记录了操作人的IP地址(这里我使用的是localhost所以IP是127.0.0.1)和操作时间。但是这里有一个问题：没有记录操作人的ID，也即creator_id字段为空，如果不知道这条记录是谁的，那这个功能就没有意义了，所以在方法三我将会说一下如何记录每一行数据的创建者和修改者。

方法三、记录每一行数据的创建者和修改者

这个功能的实现需要用到一个非常关键的东西：用户上下文。如何实现请看：《优化接口设计的思路》系列：第二篇—接口用户上下文的设计与实现。

那么现在假设我已经有了GlobalUserContext.getUserContext()方法可以获取到用户上下文信息，如何使用呢？
方法二没有记录操作人的ID，现在可以可以通过下面这种方法获取当前操作人的ID：

log.setCreatorId(GlobalUserContext.getUserContext().getUserId());

但是！！！我这里的标题是：记录每一行数据的创建者和修改者，可不仅仅是只操作user_oper_log的每一行数据，而是系统中的每一张表的每一行数据！那现在问题来了，如何实现这个需求？
最笨的办法就是在每个新增、更新的代码下都加上setCreatorId和setModifierId这些代码，实现是可以实现，但是感觉太low了，所以我这里提供一个思路和一个例子来优化这些代码。

1、统一字段名和类型

在每张表中都加入gmt_create(datetime 创建时间)、gmt_modified(datetime 更新时间)、creator_id(bigint 创建人ID)、modifier_id(bigint 更新人ID)，我们将所有表中的这些辅助字段统一命名、统一类型，这样给我们统一处理提供了基础。

2、将这些字段集成到一个抽象类中

这样做的好处有两个：

其他表的DO类继承这个抽象类，那么DO中就不需要再定义以上4个字段
统一处理的类只有抽象类一个了

tips：非常建议使用mybatis-plus来实现这个功能，maven依赖如下：

 <!-- mybatis-plus -->
<dependency>
            <groupId>com.baomidou</groupId>
            <artifactId>mybatis-plus-boot-starter</artifactId>
            <version>3.3.2</version>
</dependency>
<dependency>
            <groupId>com.baomidou</groupId>
            <artifactId>mybatis-plus-extension</artifactId>
            <version>3.3.2</version>
</dependency>

类名定义和代码如下
AbstractBaseDO.java

package com.summo.entity;

import java.io.Serializable;
import java.util.Date;

import com.baomidou.mybatisplus.annotation.FieldFill;
import com.baomidou.mybatisplus.annotation.TableField;
import com.baomidou.mybatisplus.extension.activerecord.Model;
import lombok.Getter;
import lombok.Setter;

@Getter
@Setter
public class AbstractBaseDO<T extends Model<T>> extends Model<T> implements Serializable {

    /**
     * 创建时间
     */
    @TableField(fill = FieldFill.INSERT)
    private Date gmtCreate;

    /**
     * 修改时间
     */
    @TableField(fill = FieldFill.INSERT_UPDATE)
    private Date gmtModified;

    /**
     * 创建人ID
     */
    @TableField(fill = FieldFill.INSERT)
    private Long creatorId;

    /**
     * 修改人ID
     */
    @TableField(fill = FieldFill.INSERT_UPDATE)
    private Long modifierId;

}

3、使用mybatis-plus的MetaObjectHandler全局拦截insert和update操作

自定义MetaObjectHandlerConfig继承MetaObjectHandler，代码如下
MetaObjectHandlerConfig.java

package com.summo.entity;

import com.baomidou.mybatisplus.core.handlers.MetaObjectHandler;
import org.apache.ibatis.reflection.MetaObject;

@Configuration
public class MetaObjectHandlerConfig implements MetaObjectHandler {
    @Override
    public void insertFill(MetaObject metaObject) {

    }

    @Override
    public void updateFill(MetaObject metaObject) {

    }
}

逻辑补全的代码如下

package com.summo.entity;

import java.util.Calendar;
import java.util.Date;

import com.baomidou.mybatisplus.core.handlers.MetaObjectHandler;
import com.summo.context.GlobalUserContext;
import com.summo.context.UserContext;
import org.apache.ibatis.reflection.MetaObject;

@Configuration
public class MetaObjectHandlerConfig implements MetaObjectHandler {
    @Override
    public void insertFill(MetaObject metaObject) {
        //获取用户上下文
        UserContext userContext = GlobalUserContext.getUserContext();
        //获取创建时间
        Date date = Calendar.getInstance().getTime();
        //设置gmtCreate
        this.fillStrategy(metaObject, "gmtCreate", date);
        //设置gmtModified
        this.fillStrategy(metaObject, "gmtModified", date);
        //设置creatorId
        this.fillStrategy(metaObject, "creatorId", userContext.getUserId());
        //设置modifierId
        this.fillStrategy(metaObject, "modifierId", userContext.getUserId());
    }

    @Override
    public void updateFill(MetaObject metaObject) {
        //获取用户上下文
        UserContext userContext = GlobalUserContext.getUserContext();
        //获取更新时间
        Date date = Calendar.getInstance().getTime();
        //更新操作修改gmtModified
        this.setFieldValByName("gmtModified", date, metaObject);
        //更新操作修改modifierId
        this.setFieldValByName("modifierId", userContext.getUserId(), metaObject);
    }
}