SpringBoot實戰 之 接口日志篇

在本篇文章中不會詳細介紹日志如何配置、如果切換另外一種日志工具之類的內容，只用於記錄作者本人在工作過程中對日志的幾種處理方式。

1. Debug 日志管理

在開發的過程中，總會遇到各種莫名其妙的問題，而這些問題的定位一般會使用到兩種方式，第一種是通過手工 Debug 代碼，第二種則是直接查看日志輸出。Debug 代碼這種方式只能在 IDE 下使用，一旦程序移交部署，就只能通過日志來跟蹤定位了。

在測試環境下，我們無法使用 Debug 代碼來定位問題，所以這時候需要記錄所有請求的參數及對應的響應報文。而在 數據交互篇 中，我們將請求及響應的格式都定義成了Json，而且傳輸的數據還是存放在請求體里面。而請求體對應在 HttpServletRequest 里面又只是一個輸入流，這樣的話，就無法在過濾器或者攔截器里面去做日志記錄了，而必須要等待輸入流轉換成請求模型后（響應對象轉換成輸出流前）做數據日志輸出。

有目標那就好辦了，只需要找到轉換發生的地方就可以植入我們的日志了。通過源碼的閱讀，終於在 AbstractMessageConverterMethodArgumentResolver 個類中發現了我們的期望的那個地方，對於請求模型的轉換，實現代碼如下：

@SuppressWarnings("unchecked")
protected <T> Object readWithMessageConverters(HttpInputMessage inputMessage, MethodParameter parameter,
        Type targetType) throws IOException, HttpMediaTypeNotSupportedException, HttpMessageNotReadableException {

    MediaType contentType;
    boolean noContentType = false;
    try {
        contentType = inputMessage.getHeaders().getContentType();
    }
    catch (InvalidMediaTypeException ex) {
        throw new HttpMediaTypeNotSupportedException(ex.getMessage());
    }
    if (contentType == null) {
        noContentType = true;
        contentType = MediaType.APPLICATION_OCTET_STREAM;
    }

    Class<?> contextClass = (parameter != null ? parameter.getContainingClass() : null);
    Class<T> targetClass = (targetType instanceof Class ? (Class<T>) targetType : null);
    if (targetClass == null) {
        ResolvableType resolvableType = (parameter != null ?
                ResolvableType.forMethodParameter(parameter) : ResolvableType.forType(targetType));
        targetClass = (Class<T>) resolvableType.resolve();
    }

    HttpMethod httpMethod = ((HttpRequest) inputMessage).getMethod();
    Object body = NO_VALUE;

    try {
        inputMessage = new EmptyBodyCheckingHttpInputMessage(inputMessage);

        for (HttpMessageConverter<?> converter : this.messageConverters) {
            Class<HttpMessageConverter<?>> converterType = (Class<HttpMessageConverter<?>>) converter.getClass();
            if (converter instanceof GenericHttpMessageConverter) {
                GenericHttpMessageConverter<?> genericConverter = (GenericHttpMessageConverter<?>) converter;
                if (genericConverter.canRead(targetType, contextClass, contentType)) {
                    if (logger.isDebugEnabled()) {
                        logger.debug("Read [" + targetType + "] as \"" + contentType + "\" with [" + converter + "]");
                    }
                    if (inputMessage.getBody() != null) {
                        inputMessage = getAdvice().beforeBodyRead(inputMessage, parameter, targetType, converterType);
                        body = genericConverter.read(targetType, contextClass, inputMessage);
                        body = getAdvice().afterBodyRead(body, inputMessage, parameter, targetType, converterType);
                    }
                    else {
                        body = getAdvice().handleEmptyBody(null, inputMessage, parameter, targetType, converterType);
                    }
                    break;
                }
            }
            else if (targetClass != null) {
                if (converter.canRead(targetClass, contentType)) {
                    if (logger.isDebugEnabled()) {
                        logger.debug("Read [" + targetType + "] as \"" + contentType + "\" with [" + converter + "]");
                    }
                    if (inputMessage.getBody() != null) {
                        inputMessage = getAdvice().beforeBodyRead(inputMessage, parameter, targetType, converterType);
                        body = ((HttpMessageConverter<T>) converter).read(targetClass, inputMessage);
                        body = getAdvice().afterBodyRead(body, inputMessage, parameter, targetType, converterType);
                    }
                    else {
                        body = getAdvice().handleEmptyBody(null, inputMessage, parameter, targetType, converterType);
                    }
                    break;
                }
            }
        }
    }
    catch (IOException ex) {
        throw new HttpMessageNotReadableException("Could not read document: " + ex.getMessage(), ex);
    }

    if (body == NO_VALUE) {
        if (httpMethod == null || !SUPPORTED_METHODS.contains(httpMethod) ||
                (noContentType && inputMessage.getBody() == null)) {
            return null;
        }
        throw new HttpMediaTypeNotSupportedException(contentType, this.allSupportedMediaTypes);
    }

    return body;
}

　　

上面的代碼中有一處非常重要的地方，那就在在數據轉換前后都存在 Advice 相關的方法調用，顯然，只需要在 Advice 里面完成日志記錄就可以了，下面開始實現自定義 Advice。

首先，請求體日志切面 LogRequestBodyAdvice 實現如下：

@ControllerAdvice
public class LogRequestBodyAdvice implements RequestBodyAdvice {

    private Logger logger = LoggerFactory.getLogger(LogRequestBodyAdvice.class);

    @Override
    public boolean supports(MethodParameter methodParameter, Type targetType,
                            Class<? extends HttpMessageConverter<?>> converterType) {
        return true;
    }

    @Override
    public Object handleEmptyBody(Object body, HttpInputMessage inputMessage,
                                  MethodParameter parameter, Type targetType,
                                  Class<? extends HttpMessageConverter<?>> converterType) {
        return body;
    }

    @Override
    public HttpInputMessage beforeBodyRead(HttpInputMessage inputMessage,
                                           MethodParameter parameter, Type targetType,
                                           Class<? extends HttpMessageConverter<?>> converterType) throws IOException {
        return inputMessage;
    }

    @Override
    public Object afterBodyRead(Object body, HttpInputMessage inputMessage,
                                MethodParameter parameter, Type targetType,
                                Class<? extends HttpMessageConverter<?>> converterType) {
        Method method = parameter.getMethod();
        String classMappingUri = getClassMappingUri(method.getDeclaringClass());
        String methodMappingUri = getMethodMappingUri(method);
        if (!methodMappingUri.startsWith("/")) {
            methodMappingUri = "/" + methodMappingUri;
        }
        logger.debug("uri={} | requestBody={}", classMappingUri + methodMappingUri, JSON.toJSONString(body));
        return body;
    }

    private String getMethodMappingUri(Method method) {
        RequestMapping methodDeclaredAnnotation = method.getDeclaredAnnotation(RequestMapping.class);
        return methodDeclaredAnnotation == null ? "" : getMaxLength(methodDeclaredAnnotation.value());
    }

    private String getClassMappingUri(Class<?> declaringClass) {
        RequestMapping classDeclaredAnnotation = declaringClass.getDeclaredAnnotation(RequestMapping.class);
        return classDeclaredAnnotation == null ? "" : getMaxLength(classDeclaredAnnotation.value());
    }

    private String getMaxLength(String[] strings) {
        String methodMappingUri = "";
        for (String string : strings) {
            if (string.length() > methodMappingUri.length()) {
                methodMappingUri = string;
            }
        }
        return methodMappingUri;
    }
}

　　

得到日志記錄如下：

2017-05-02 22:48:15.435 DEBUG 888 --- [nio-8080-exec-1] c.q.funda.advice.LogRequestBodyAdvice    : uri=/sys/user/login | 
requestBody={"password":"123","username":"123"}

對應的，響應體日志切面 LogResponseBodyAdvice 實現如下：

@ControllerAdvice
public class LogResponseBodyAdvice implements ResponseBodyAdvice {

    private Logger logger = LoggerFactory.getLogger(LogResponseBodyAdvice.class);

    @Override
    public boolean supports(MethodParameter returnType, Class converterType) {
        return true;
    }

    @Override
    public Object beforeBodyWrite(Object body, MethodParameter returnType, MediaType selectedContentType, Class selectedConverterType, ServerHttpRequest request, ServerHttpResponse response) {
        logger.debug("uri={} | responseBody={}", request.getURI().getPath(), JSON.toJSONString(body));
        return body;
    }
}

　　

得到日志記錄如下：

2017-05-02 22:48:15.520 DEBUG 888 --- [nio-8080-exec-1] c.q.funda.advice.LogResponseBodyAdvice   : uri=/sys/user/login | 
responseBody={"code":10101,"msg":"手機號格式不合法"}

　　

2. 異常日志管理

Debug 日志只適用於開發及測試階段，一般應用部署生產，鑒於日志里面的敏感信息過多，往往只會在程序出現異常時輸出明細的日志信息，在 ExceptionHandler 標注的方法里面輸入異常日志無疑是最好的，但擺在面前的一個問題是，如何將 @RequestBody 綁定的 Model 傳遞給異常處理方法？我想到的是通過 ThreadLocal 這個線程本地變量來存儲每一次請求的 Model，這樣就可以貫穿整個請求處理流程，下面使用 ThreadLocal 來協助完成異常日志的記錄。

在綁定時，將綁定 Model 有存放到 ThreadLocal：

 

@RestController
@RequestMapping("/sys/user")
public class UserController {

    public static final ThreadLocal<Object> MODEL_HOLDER = new ThreadLocal<>();

    @InitBinder
    public void initBinder(WebDataBinder webDataBinder) {
        MODEL_HOLDER.set(webDataBinder.getTarget());
    }

}

　　

異常處理時，從 ThreadLocal 中取出變量，並做相應的日志輸出：

@ControllerAdvice
@ResponseBody
public class ExceptionHandlerAdvice {

    private Logger logger = LoggerFactory.getLogger(ExceptionHandlerAdvice.class);

    @ExceptionHandler(Exception.class)
    public Result handleException(Exception e, HttpServletRequest request) {
        logger.error("uri={} | requestBody={}", request.getRequestURI(),
                JSON.toJSONString(UserController.MODEL_HOLDER.get()));
        return new Result(ResultCode.WEAK_NET_WORK);
    }

}

　　

當異常產生時，輸出日志如下：

2017-05-03 21:46:07.177 ERROR 633 --- [nio-8080-exec-1] c.q.funda.advice.ExceptionHandlerAdvice  : uri=/sys/user/login | 
requestBody={"password":"123","username":"13632672222"}

　　

注意：當 Mapping 方法中帶有多個參數時，需要將 @RequestBody 綁定的變量當作方法的最后一個參數，否則 ThreadLocal 中的值將會被其它值所替換。如果需要輸出 Mapping 方法中所有參數，可以在 ThreadLocal 里面存放一個 Map 集合。

項目的 github 地址：https://github.com/qchery/funda

原文地址：http://blog.csdn.net/chinrui/article/details/71056847