如何记录请求信息，以及Spring Boot应用程序中的每个公共方法调用?

Question

我曾经帮助过一个项目，在这个项目中，每个对Spring Boot REST API的传入请求以及每个公共方法调用都被记录到一个滚动文件中。

程序使用以下格式记录每个请求:

{DATE} {TIME} | {APACHE_REQUEST_ID} {TOMCAT_REQUEST_ID} | {LOG_LEVEL} | DispatcherServlet | GET /my-endpoint/uri?param1=value1&param2=value2, parameters={masked}
{DATE} {TIME} | {APACHE_REQUEST_ID} {TOMCAT_REQUEST_ID} | {LOG_LEVEL} | {PACKAGE_NAME} | {MyClassName.methodName} | >>> | {ParameterName} |
{DATE} {TIME} | {APACHE_REQUEST_ID} {TOMCAT_REQUEST_ID} | {LOG_LEVEL} | {PACKAGE_NAME} | {MyClassName.methodName} | <<< | {ParameterName} | {TIME} ms

我试着复制这种行为，但我似乎找不到正确的方法。

我试着:

• HandlerInterceptorAdapterwithWebMvcConfigurer
• 春季启动CommonsRequestLoggingFilter
• Spring AOP@Aspect

但是我似乎找不到合适的技术来获得我上面指定的输出。

我知道的:

• 该项目是Spring BootREST API，使用log4j2
我们使用一个XML文件来配置公共方法调用的日志记录。这个文件允许我们指定要记录哪些包的公共方法调用。

如何使用Spring Boot和log4j2实现此目标?

Answer 1

您可以使用Servlet过滤器或Spring拦截器。下面是一个例子，我的一个应用程序使用一个拦截器连接到WebMvcConfigurerAdapter的addInterceptors方法中，类似于Spring Boot中添加Http请求拦截器。

/**
* Log endpoint calls with response times.  Set reduced logging level based on endpoint mapping (see log4j2.xml)
*/
public class LoggingInterceptor extends HandlerInterceptorAdapter {
private static final Logger LOGGER = LogManager.getLogger();
private final String START_TIME = "startTime";
private final String ENDPOINT_MAPPING = "endpointMapping";
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
ThreadContext.put(START_TIME, System.nanoTime() + "");
ThreadContext.put(ENDPOINT_MAPPING, getEndpointMapping(handler));
LOGGER.info("Handling request - " + getEndpoint(request) + " method: " + request.getMethod() + "Media Type: " + request.getHeader("Accepts"));
return true;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
Long startTime = Long.parseLong(ThreadContext.get(START_TIME), 10);
Long endTime = System.nanoTime();
ThreadContext.clearAll();
LOGGER.info("Completed request " + getEndpoint(request)
+ " - Response: HTTP " + response.getStatus() + " in " + ((endTime-startTime)/1000000) + "ms");
}
public String getEndpoint(HttpServletRequest request) {
return request.getMethod() + " " + request.getRequestURI();
}
//Determines the endpoint based on the Spring annotation of given handler method.
//Does not include additional path from Controller class annotations however.
public String getEndpointMapping(Object handler) {
if (handler instanceof HandlerMethod) {
HandlerMethod handlerMethod = (HandlerMethod) handler;
Method method = handlerMethod.getMethod();
if (method == null) {
return "";
}
GetMapping get = method.getAnnotation(GetMapping.class);
if (get != null) {
return "GET " + firstValue(get.value());
}
PostMapping post = method.getAnnotation(PostMapping.class);
if (post != null) {
return "POST " + firstValue(post.value());
}
PutMapping put = method.getAnnotation(PutMapping.class);
if (put != null) {
return "PUT " + firstValue(put.value());
}
DeleteMapping delete = method.getAnnotation(DeleteMapping.class);
if (delete != null) {
return "DELETE " + firstValue(delete.value());
}
PatchMapping patch = method.getAnnotation(PatchMapping.class);
if (patch != null) {
return "PATCH " + firstValue(patch.value());
}
RequestMapping generic = method.getAnnotation(RequestMapping.class);
if (generic != null) {
return firstValue(generic.method()) + " " + firstValue(generic.value());
}
}
return "";
}
private <T> String firstValue(T[] values) {
if (values == null || values.length == 0 || values[0] == null) {
return "";
}
return values[0].toString();
}
}

消息使用的模式是

"%d [%t] %-5p %X{loginId, userId, ipAddress, accountNumber} %C{1}.%M:%L - %m%n"

结果输出为

2021-03-08 23:29:38,567 [http-nio-8091-exec-178] INFO  {} LoggingInterceptor.preHandle:33 - Handling request - GET /service/v1/dosomething method: GET Media Type: null
2021-03-08 23:29:38,617 [http-nio-8091-exec-178] INFO  {} LoggingInterceptor.afterCompletion:42 - Completed request GET /service/v1/dosomething - Response: HTTP 200 in 50ms

如果你想要一个更灵活的方式来显示时间，看看Log4j审计如何在它的RequestContextFilter中使用ElapsedUtil来格式化经过的时间。

使用过滤器比拦截器有一个优势，它可以计算本地变量中的时间，而不像拦截器那样需要使用ThreadLocal。