前言
在一些场景中我们希望能够记录Http的请求地址、请求参数、应答数据、请求处理时间等信息。如果一个接口一个接口的增加日志太过浪费时间,而且容易发生遗漏。那么借助Spring AOP 对接口统一处理,肯定是比较好的方法。
Demo地址
开始之前
在开始之前我们需要先了解下以下知识。
通过上下文获取request和response
代码如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 private HttpServletRequest getRequest () { Optional<RequestAttributes> requestAttributesOptional = Optional.ofNullable(RequestContextHolder.getRequestAttributes()); if (requestAttributesOptional.isPresent()) { var servletRequestAttributes = (ServletRequestAttributes) requestAttributesOptional.get(); return servletRequestAttributes.getRequest(); } else { throw new LogPointAspectException ("Could not get the HttpServletRequest from the spring webmvc context." ); } } private HttpServletResponse getResponse () { Optional<RequestAttributes> requestAttributesOptional = Optional.ofNullable(RequestContextHolder.getRequestAttributes()); if (requestAttributesOptional.isPresent()) { var servletRequestAttributes = (ServletRequestAttributes) requestAttributesOptional.get(); return servletRequestAttributes.getResponse(); } else { throw new LogPointAspectException ("Could not get the HttpServletResponse from the spring webmvc context." ); } }
之所以能够获取到是因为每次请求都会创建一个线程,Spring把request和response放到了线程的ThreadLocal
中。具体细节可查看RequestContextHolder
的源码,这不是本文的重点。
Spring AOP的两种配置配置方式
方法一、通过注解配置
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 @Component @Aspect public class RequestAspect { @Pointcut("execution(* org.depsea.log..*Controller.*(..))") private void pointcut () { } @Around("pointcut()") public Object aroundAdvice (ProceedingJoinPoint joinPoint) throws Throwable { Object result = null ; try { result = joinPoint.proceed(); } catch (Throwable ex) { throw ex; } return result; } }
@Component
:声明为Spring Bean,必须
@Aspect
:AspectJ注解声明支持,Spring仅使用了AspectJ的声明注解,底层代理的实现还是用的JDK动态代理或者cglib来实现。
@Pointcut
:声明切入点
@Around
:声明这是一个环绕通知,使用环绕通知有利于我们计算接口的耗时,以及对异常的记录。
方法二、配置式
核心接口:
org.aopalliance.aop.Advice
org.springframework.aop.Advisor
这里我们主要实现 Advice
接口,Advice接口有如下几种:
org.springframework.aop.MethodBeforeAdvice
:在方法开始执行之前织入
org.springframework.aop.AfterReturningAdvice
:在方法返回之后织入
org.springframework.aop.ThrowsAdvice
:在方法发生异常时织入
MethodBeforeAdvice
必定会执行,如果方法没有发生异常,则AfterReturningAdvice
执行;如果方法发生异常,则ThrowsAdvice
执行。
Advice
主要实现通知处理,是我们需要实现的功能。在Spring中配置如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 @Configuration public class ApplicationConfiguration { @Bean public Advisor requestAdvisor (Advice requestAdvice) { var pointcut = new AspectJExpressionPointcut (); pointcut.setExpression("execution(* org.depsea..*.controller.*.*(..))" ); return new DefaultPointcutAdvisor (pointcut, requestAdvice); } @Bean public Advice requestAdvice (Tracer tracer) { var requestAdvice = new RequestAdvice (); requestAdvice.setTracer(tracer); requestAdvice.setApiNameGetter(new Swagger2ApiNameGetterImpl ()); requestAdvice.addPointHandlers(new RequestLogHandler (), new ElasticsearchRequestPointHandler ()); return requestAdvice; } }
本文中采用的是第二种配置方式,目的是为了做成一个框架。可以供多个项目使用,各个项目只需要做简单配置即可实现请求信息的提取以及请求信息的记录。
请求信息提取
RequestPoint
我们定义一个RequestPoint
类来存储提取的请求信息。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 @Data public class RequestPoint { private String applicationName; private String traceId; private String spanId; private String parentId; private String moduleName; private String apiName; private String schema; private String requestMethod; private String requestUri; private String serverLocalIp; private String clazz; private String methodName; private String requestParameterMap; private String methodParameterMap; private String returnValue; private long timeConsuming; private boolean error; private String errorMessage; private String exceptionName; private String exceptionStack; private Date timestamp; private int responseStatus; private String requestHeaders; private String responseHeaders; private String cookies; private String userId; private String name; }
我们可以提取的信息多达27项,其实还可以更多,比如浏览器信息,甚至可以通过浏览器信息获取到访问的设备类型等,以及用户的操作系统等数据。
扩展点
提供了几个扩展点,如下:
org.depsea.log.getter.ApiNameGetter
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 public interface ApiNameGetter { String getOperationName (Method method) ; String getModuleName (Class<?> targetClazz) ; }
此扩展点主要用于通过控制层的注解实现获取模块名称及接口名称的功能。
org.depsea.log.getter.UserGetter
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 public interface UserGetter { String getUserId () ; String getName () ; }
此扩展点用于获取当前登陆的用户信息,可以针对spring security 和 shiro 添加自己的实现。
org.depsea.log.handler.RequestPointHandler
1 2 3 4 5 6 7 8 9 10 11 12 13 public interface RequestPointHandler { default boolean isAsync () { return false ; } void handle (RequestPoint requestPoint) ; }
此扩展点用于后请求信息的处理,如果是异步的,则会放到线程池中处理,不影响当前线程。
比如将请求信息打印到控制台,将请求信息保存至数据库或ES或MongoDB中等。
RequestAdvice
此处不列出完整代码,近贴出部分代码,完整代码可以到gitee中查看。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 public class RequestAdvice implements AfterReturningAdvice , ThrowsAdvice, MethodBeforeAdvice, ApplicationContextAware { private final ExecutorService executorService = Executors.newCachedThreadPool(); private boolean includeRequestHeaders = true ; private boolean includeResponseHeaders = true ; private ApiNameGetter apiNameGetter; private UserGetter userGetter; private Tracer tracer; private final ThreadLocal<Long> timeConsumingThreadLocal = new ThreadLocal <>(); private final ObjectMapper objectMapper = new ObjectMapper (); private List<RequestPointHandler> requestPointHandlers = new ArrayList <>(); private ApplicationContext applicationContext; }
前置通知
org.springframework.aop.MethodBeforeAdvice
的实现。
1 2 3 4 5 @Override public void before (@NonNull Method method, @NonNull Object[] args, Object target) throws Throwable { timeConsumingThreadLocal.set(System.currentTimeMillis()); }
在方法开始时仅记录开始时间。
后置通知
org.springframework.aop.AfterReturningAdvice
的实现
1 2 3 4 5 6 7 8 9 10 11 12 @Override public void afterReturning (Object returnValue, @NonNull Method method, @NonNull Object[] args, Object target) throws Throwable { try { var requestPoint = this .createRequestPoint(method, args); if (returnValue != null ) { requestPoint.setReturnValue(this .objectMapper.writeValueAsString(returnValue)); } this .doRequestHandler(requestPoint); } catch (Exception ex) { log.warn("处理失败:{}" , ex.getMessage()); } }
异常通知
org.springframework.aop.ThrowsAdvice
的实现。
方法格式:void afterThrowing([Method, args, target], ThrowableSubclass);
示例:
public void afterThrowing(Exception ex)
public void afterThrowing(RemoteException)
public void afterThrowing(Method method, Object[] args, Object target, Exception ex)
public void afterThrowing(Method method, Object[] args, Object target, ServletException ex)
以上信息从源码注释中查看
1 2 3 4 5 6 7 8 9 10 11 12 public void afterThrowing (Method method, Object[] args, Object target, Exception ex) { try { var requestPoint = this .createRequestPoint(method, args); requestPoint.setError(true ); requestPoint.setExceptionName(ex.getClass().getName()); requestPoint.setExceptionStack(ExceptionUtils.getStackTrace(ex)); requestPoint.setErrorMessage(ex.getMessage()); this .doRequestHandler(requestPoint); } catch (Exception e) { log.warn("处理失败:{}" , e.getMessage()); } }
createRequestPoint
这个方法用于获取请求信息、链路信息、接口信息、用户信息等。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 private RequestPoint createRequestPoint (@NonNull Method method, @NonNull Object[] args) throws JsonProcessingException { var request = this .getRequest(); var response = this .getResponse(); var requestPoint = new RequestPoint (); if (this .includeRequestHeaders) { requestPoint.setRequestHeaders(this .objectMapper.writeValueAsString(this .getRequestHeaders(request))); } if (this .includeResponseHeaders && response != null ) { requestPoint.setResponseHeaders(this .objectMapper.writeValueAsString(this .getResponseHeaders(response))); } if (this .apiNameGetter != null ) { requestPoint.setModuleName(this .apiNameGetter.getModuleName(method.getDeclaringClass())); requestPoint.setApiName(this .apiNameGetter.getOperationName(method)); } if (this .userGetter != null ) { requestPoint.setUserId(this .userGetter.getUserId()); requestPoint.setName(this .userGetter.getName()); } requestPoint.setApplicationName(this .getApplicationName()); requestPoint.setClazz(method.getDeclaringClass().getName()); requestPoint.setMethodName(method.getName()); requestPoint.setError(false ); requestPoint.setTimestamp(new Date ()); if (this .tracer != null ) { var span = tracer.currentSpan(); if (span != null ) { requestPoint.setSpanId(span.context().spanId()); requestPoint.setTraceId(span.context().traceId()); requestPoint.setParentId(span.context().parentId()); } } requestPoint.setSchema(request.getScheme().toUpperCase()); requestPoint.setRequestMethod(request.getMethod().toUpperCase()); requestPoint.setRequestUri(request.getRequestURI()); Map<String, Object> methodParams = new HashMap <>(); Parameter[] parameters = method.getParameters(); for (var i = 0 ; i < parameters.length; i++) { var parameter = parameters[i]; methodParams.put(parameter.getName(), args[i]); } requestPoint.setMethodParameterMap(objectMapper.writeValueAsString(methodParams)); requestPoint.setRequestParameterMap(objectMapper.writeValueAsString(request.getParameterMap())); if (response != null ) { requestPoint.setResponseStatus(response.getStatus()); } long start = this .timeConsumingThreadLocal.get(); long end = System.currentTimeMillis(); requestPoint.setTimeConsuming(end - start); this .timeConsumingThreadLocal.remove(); return requestPoint; }
doRequestHandler
用于对请求信息进行处理
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 private void doRequestHandler (RequestPoint requestPoint) { if (!CollectionUtils.isEmpty(this .requestPointHandlers)) { for (RequestPointHandler requestPointHandler : this .requestPointHandlers) { try { if (requestPointHandler.isAsync()) { this .executorService.submit(() -> requestPointHandler.handle(requestPoint)); } else { requestPointHandler.handle(requestPoint); } } catch (Exception ex) { log.warn("Execute request point handler [{}] fail. Cause: {}" , requestPointHandler.getClass().getName(), ex.getMessage(), ex); } } } }
RequestPointHandler实现
本文提供一个打印日志的实现,如有其他需求可自行实现。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 @Slf4j public class RequestLogHandler implements RequestPointHandler { @Override public void handle (RequestPoint requestPoint) { log.info("Request Info: {} {} {}" , requestPoint.getSchema(), requestPoint.getRequestMethod(), requestPoint.getRequestUri()); log.info("Controller & Method: {}#{}" , requestPoint.getClazz(), requestPoint.getMethodName()); log.info("Request Parameters: {}" , requestPoint.getRequestParameterMap()); log.info("Method Parameters: {}" , requestPoint.getMethodParameterMap()); if (requestPoint.isError()) { log.warn("Request Error: {}" , requestPoint.getErrorMessage()); } else { log.info("Return Value:{}" , requestPoint.getReturnValue()); } log.info("Time Consuming: {}" , requestPoint.getTimeConsuming()); } }
效果如下:
1 2 3 4 5 6 ...RequestLogHandler : Request Info: HTTP GET /api/v1/test ...RequestLogHandler : Controller & Method: org.depsea.log.module.controller.TestController...RequestLogHandler : Request Parameters: {"name" :["zhangsan" ]}...RequestLogHandler : Method Parameters: {"name" :"zhangsan" }...RequestLogHandler : Return Value:"OK" ...RequestLogHandler : Time Consuming: 50