前言
面向切面编程 是 Spring 里一种很不错的编程思想，简单来讲就是可以将一段功能代码在程序运行时，动态地将该段代码切入到目标方法前或后插入去执行，这种方式可以实现代码的可插拔性，之前我们在拦截器实战篇中说过的拦截器其实就是切面编程的一种实现。
本篇文章我们将带你使用 Spring 的 @Aspect 注解来实现 Controller 层方法的请求参数、响应体的日志打印功能，这在企业开发中也是很有必要的哦，可以减少我们浪费在日志打印上的一些时间，也可以统一日志的打印格式，以后在使用 ELK 这种日志搜索服务时，你也将会得到很不错的使用体验。
思路
我们使用 @Aspect 标识一个切面类，使用 @Around 注解标识在你打印日志的方法里，主要捕捉@RestController 带这个注解的类方法，也就是我们的 RestController下的方法，这样就可以在joinPoint.proceed() 程序的处理前后打印上日志信息，我们目前打印的主要信息有，请求者、请求的类.方法名字、请求的参数（参数敏感信息需要用 “**”替换）、请求者 IP、调用源、App 版本号、Api 版本号、客户端的 UserAgent 信息、响应的结果（敏感词过滤）、最后请求结束后所花费的时间。
好了，说了这么多接下来我们看下源码吧。
package cn.notemi.demo.aspect;
import java.lang.reflect.Method;
import java.util.List;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import cn.notemi.demo.model.bo.LoginUser;
import cn.notemi.demo.util.IpUtil;
import com.google.common.base.Strings;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import org.springframework.web.multipart.MultipartFile;
import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.JSONObject;
import com.google.common.collect.Lists;
import cn.notemi.demo.constant.HeaderConstants;
import cn.notemi.demo.handler.GlobalExceptionHandler;
import cn.notemi.demo.helper.LoginTokenHelper;
/**
* @desc 请求参数、响应体统一日志打印
*/
@Aspect
@Component
public class RestControllerAspect {
private final Logger logger = LoggerFactory.getLogger(this.getClass());
/**
* 环绕通知
* @param joinPoint 连接点
* @return 切入点返回值
* @throws Throwable 异常信息
*/
@Around("@within(org.springframework.web.bind.annotation.RestController) || @annotation(org.springframework.web.bind.annotation.RestController)")
public Object apiLog(ProceedingJoinPoint joinPoint) throws Throwable {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
Method method = signature.getMethod();
boolean logFlag = this.needToLog(method);
if (!logFlag) {
return joinPoint.proceed();
}
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
LoginUser loginUser = LoginTokenHelper.getLoginUserFromRequest();
String ip = IpUtil.getRealIp(request);
String methodName = this.getMethodName(joinPoint);
String params = this.getParamsJson(joinPoint);
String requester = loginUser == null ? "unknown" : String.valueOf(loginUser.getId());
String callSource = request.getHeader(HeaderConstants.CALL_SOURCE);
String appVersion = request.getHeader(HeaderConstants.APP_VERSION);
String apiVersion = request.getHeader(HeaderConstants.API_VERSION);
String userAgent = request.getHeader("user-agent");
logger.info("Started request requester [{}] method [{}] params [{}] IP [{}] callSource [{}] appVersion [{}] apiVersion [{}] userAgent [{}]",
requester, methodName, params, ip, callSource, appVersion, apiVersion, userAgent);
long start = System.currentTimeMillis();
Object result = joinPoint.proceed();
logger.info("Ended request requester [{}] method [{}] params[{}] response is [{}] cost [{}] millis ",
requester, methodName, params, this.deleteSensitiveContent(result), System.currentTimeMillis() - start);
return result;
}
private String getMethodName(ProceedingJoinPoint joinPoint) {
String methodName = joinPoint.getSignature().toShortString();
String SHORT_METHOD_NAME_SUFFIX = "(..)";
if (methodName.endsWith(SHORT_METHOD_NAME_SUFFIX)) {
methodName = methodName.substring(0, methodName.length() - SHORT_METHOD_NAME_SUFFIX.length());
}
return methodName;
}
private String getParamsJson(ProceedingJoinPoint joinPoint) {
Object[] args = joinPoint.getArgs();
StringBuilder sb = new StringBuilder();
for (Object arg : args) {
//移除敏感内容
String paramStr;
if (arg instanceof HttpServletResponse) {
paramStr = HttpServletResponse.class.getSimpleName();
} else if (arg instanceof HttpServletRequest) {
paramStr = HttpServletRequest.class.getSimpleName();
} else if (arg instanceof MultipartFile) {
long size = ((MultipartFile) arg).getSize();
paramStr = MultipartFile.class.getSimpleName() + " size:" + size;
} else {
paramStr = this.deleteSensitiveContent(arg);
}
sb.append(paramStr).append(",");
}
if (Strings.isNullOrEmpty(sb.toString())) {
return null;
}
return sb.deleteCharAt(sb.length() - 1).toString();
}
/**
* 判断是否需要记录日志
*/
private boolean needToLog(Method method) {
// 对 `@GetMapping` 注解注释的方法和 `GlobalExceptionHandler` 这个类下的所有方法都不需要打印日志
return method.getAnnotation(GetMapping.class) == null
&& !method.getDeclaringClass().equals(GlobalExceptionHandler.class);
}
/**
* 删除参数中的敏感内容
* @param obj 参数对象
* @return 去除敏感内容后的参数对象
*/
private String deleteSensitiveContent(Object obj) {
JSONObject jsonObject = new JSONObject();
if (obj == null || obj instanceof Exception) {
return jsonObject.toJSONString();
}
try {
String param = JSON.toJSONString(obj);
jsonObject = JSONObject.parseObject(param);
List<String> sensitiveFieldList = this.getSensitiveFieldList();
for (String sensitiveField : sensitiveFieldList) {
if (jsonObject.containsKey(sensitiveField)) {
jsonObject.put(sensitiveField, "******");
}
}
} catch (ClassCastException e) {
return String.valueOf(obj);
}
return jsonObject.toJSONString();
}
/**
* 敏感字段列表（当然这里你可以更改为可配置的）
*/
private List<String> getSensitiveFieldList() {
List<String> sensitiveFieldList = Lists.newArrayList();
sensitiveFieldList.add("pwd");
sensitiveFieldList.add("password");
return sensitiveFieldList;
}
}下面我们解释几处你可能不太清楚的代码逻辑。
下面的逻辑是对 @GetMapping 注解注释的方法和 GlobalExceptionHandler 这个类下的所有方法都不需要打印日志，也就是说我们不需要打印GET请求因为这通常不会对数据做出更改操作（当然这需要你的系统以Restful的风格去命名方法），还有就是全局异常处理类也会不需要打印日志，这个类我们后续会说。
private boolean needToLog(Method method) {
return method.getAnnotation(GetMapping.class) == null
&& !method.getDeclaringClass().equals(GlobalExceptionHandler.class);
}如果你很认真的读懂了这段代码，你会发现上面的 joinPoint.proceed() 代码如果出现了异常，响应结果的日志就打不出来了，其实这是有原因的，在出现异常的情况下，日志交由 GlobalExceptionHandler 全局异常处理类去打印就好了。
如果你很疑惑下面获取用户的这句代码是如何写的，你可以读下这两篇文章 登录校验、统一参数校验
演示
以创建用户为例：
@RestController
@RequestMapping("/user")
public class UserController {
@PostMapping
@ResponseStatus(HttpStatus.CREATED)
public User addUser(@Valid @RequestBody User user) {
user.setId("1000");
user.setCreateTime(new Date());
return user;
}
}调用API：
然后在 header 中传入 App-Version
打印日志如下：
2020-01-04 15:54:05.501 INFO 17503 --- [nio-8080-exec-4] c.n.demo.aspect.RestControllerAspect : Started request requester [unknown] method [UserController.addUser] params [{"gender":"MALE","nickname":"张三","type":"NORMAL"}] IP [192.168.123.52] callSource [null] appVersion [1.0] apiVersion [null] userAgent [PostmanRuntime/7.6.0]
2020-01-04 15:54:05.501 INFO 17503 --- [nio-8080-exec-4] c.n.demo.aspect.RestControllerAspect : Ended request requester [unknown] method [UserController.addUser] params[{"gender":"MALE","nickname":"张三","type":"NORMAL"}] response is [{"gender":"MALE","createTime":1588578845501,"nickname":"张三","id":"1000","type":"NORMAL"}] cost [0] millis
柒月君 2020-06-02 20:27
研究过高并发下 用这种方式记录日志错乱的解决办法吗？
我一直没机会遇到这种情况
Flicker博主 2020-06-05 18:28
听说过这个问题，也没遇到过这么高并发的情况。