Spring MVC统一异常处理及原理分析(二)

前言

上篇，我们已经阐述在Spring MVC中如何优雅地处理异常，并通过源码分析了其原理及工作过程。
但是一定会有同学产生疑问：原来的异常处理方式，可以直接在catch块中打印请求入参，当异常发生时，能够清晰知道是什么入参导致的异常，方便问题的排查。使用统一异常处理的方案，只打印了异常堆栈，丢失了相关上下文信息，怎么办？

try {
    // do biz
} catch (Exception e) {
    log.error("xxx method exception, param1:{}, param2:{}, param3:{}", param1, param2, param3 ,e);
}

先说说这种打印日志方式的弊端

  1. Controller层充斥着大量的try\catch块[上篇文章亦有提及]，catch的逻辑中打印了请求参数相关信息，某天在接口新增参数，很有可能漏掉在catch的日志中将之打印出来，拿排查问题的场景来说----在测试环境很容易发生新增参数，对应增加业务逻辑，但测试结果与预期不一致，但又因为漏打日志，无法确认问题所在，需要重新添加日志排查问题：修改，提交代码，发起Merge-Request，Accept，发布，整一套流程下来，耗费多少时间？另一方面，这种重复且无意义的劳动，相信大家都不愿意去做

  2. 每个人打印日志的习惯都不一样，甚至同一个人不同成长阶段都不一样。有的人喜欢用=来分割参数与值，有的人喜欢用:；有的人喜欢添加简略信息如方法名，以便于日志关键字搜索，有的人喜欢添加详细信息，便于仔细记录。那么，不一致就会带来许多的问题，比如无法做数据格式化及统一收集展示，无法基于日志对系统运行过程中的错误和潜在风险进行监控和报警，另一方面，带来的问题额外的是学习成本。举个例子，张三负责的系统出现线上问题，但张三休假了，李四帮忙排查，他就需要先看异常信息是什么，但大部分的日志打印因为不规范的原因，对问题的排查没有实质性帮助，还需要跑到代码里看对应的日志上下文含义是什么，才能理解日志的含义，以帮助排查问题，这无异于提高排查问题的门槛，即所谓的学习成本

一个系统全无日志不利于问题排查，全打日志又如同信息垃圾，反而把重点信息给掩埋。因此，如何规范化打印日志，是一门学问，是我们做为合作程序员、工程师的职业素养，也是对外界戏称我们为码农的呐喊与抗议。

在这里，我们并不讨论具体该怎样规范化打印日志，而是借着日志打印问题，提出一些思考，并尝试借着现有的一些开源框架，去解决一部分规范化日志打印的问题。

正文

在上篇中，我们提出统一异常处理的方式，仅只打印了异常堆栈，丢失了相关上下文信息，想要解决此问题，一个很自然的想法是，能不能在统一异常处理中，同样打印请求参数呢？先试着在方法中添加
HttpServletRequest参数，该思路的出发点是，只要能拿到request，就能拿到请求参数

@ExceptionHandler
@ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR) // Http Status Code 500
public ResponseDTO handleException(Exception e, HttpServletRequest request) {
    // 兜底逻辑，通常用于处理未预期的异常，比如不知道哪儿冒出来的空指针异常
    
    log.error("请求发生异常，请求参数:{}", JsonUtils.toJsonString(request.getParameterMap()), e);
    return ResponseDTO.failedResponse().withErrorMessage("服务器开小差了");
}

通过实验发现，可以拿到请求参数，这样就把请求参数打印出来了。但是这里又引入了另外一个问题，ServletRequest#getParameterMap只能拿到请query string 或者posted form data，对于post body，正常情况下，我们需要通过ServletRequest#getInputStream或者ServletRequest#getReader才能拿到请求体。

String requestBody = null;
try {
    requestBody = IOUtils.toString(request.getInputStream(), Charset.defaultCharset());
} catch (IOException ex) {
    log.info("IO 发生异常", ex);
}
log.error("请求发生异常，请求体:{}", requestBody, e);

但是，在这里，获取请求体的方式存在一些问题，原因在于: 大部分的InputStream仅允许读取一次，而对于ServletInputStream，如果进行二次读取，会直接抛出java.io.IOException: Stream closed异常。

if (closed) {
    throw new IOException(sm.getString("inputBuffer.streamClosed"));
}

在Controller的方法中使用@RequestBody注解参数，Spring MVC就会调用request.getInputStream()读取请求体，并将请求体转化成我们需要的请求参数，因此在这里已经将流读取完毕。

@PostMapping("/test")
public void test(@RequestBody XXXDTO xxxDTO) {
    // do biz
}

如果我们在后置的异常处理流程中，尝试再一次读取请求体，程序就会抛出java.io.IOException: Stream closed异常，因此，通过这种简单的方式拿不到请求体，我们需要尝试用另一种方式来获取请求体。

ContentCachingRequestWrapper
ContentCachingRequestWrapper.png

从ContentCachingRequestWrapper的继承体系图可以看出，它是一个HttpServletRequest，且是一个Wrapper，这是一个很典型的装饰器模式，从类名中，可以猜测它能够缓存请求体内容。其实现机制是代理getInputStream方法，且内部持有的一个ByteArrayOutputStream，每当从InputStream中读取内容，同时会将读取到的内容缓存到ByteArrayOutputStream中，实现数据重复利用。getContentAsByteArray方法即可返回缓存的内容

public ServletInputStream getInputStream() throws IOException {
    if (this.inputStream == null) {
        this.inputStream = new ContentCachingInputStream(getRequest().getInputStream());
    }
    return this.inputStream;
}

private class ContentCachingInputStream extends ServletInputStream {
    private final ServletInputStream is;
    private boolean overflow = false;
    public ContentCachingInputStream(ServletInputStream is) {
        this.is = is;
    }
    @Override
    public int read() throws IOException {
        int ch = this.is.read();
        if (ch != -1 && !this.overflow) {
            if (contentCacheLimit != null && cachedContent.size() == contentCacheLimit) {
                this.overflow = true;
                handleContentOverflow(contentCacheLimit);
            }
            else {
            // 将读取到的内容写到ByteArrayOutputStream
                cachedContent.write(ch);
            }
        }
        return ch;
    }
}

public byte[] getContentAsByteArray() {
    return this.cachedContent.toByteArray();
}

我们需要一个扩展点，在Spring MVC处理请求之前，能够对Request进行增强，因此，很自然想到增加一个Filter。这样，Spring MVC在后续读取请求体时，增强的Request(ContentCachingRequestWrapper)就将请求体缓存了起来，为后续统一异常处理打印请求上下文提供可能性

public class HttpRequestWrapperFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        if (isAsyncDispatch(request)) {
            filterChain.doFilter(request, response);
        } else {
            filterChain.doFilter(wrapRequest(request), response);
        }
    }

    private ContentCachingRequestWrapper wrapRequest(HttpServletRequest request) {
        if (request instanceof ContentCachingRequestWrapper) {
            return (ContentCachingRequestWrapper) request;
        } else {
            return new ContentCachingRequestWrapper(request);
        }
    }
}

接着，只需要改造GlobalExceptionHandler，在请求出现异常后，将请求上下文打印出来

public class GlobalExceptionHandler {

    private static final String LINE_SEPARATOR = System.getProperty("line.separator");

    private static final List<MediaType> VISIBLE_TYPES = Arrays.asList(
            MediaType.valueOf("text/*"),
            MediaType.APPLICATION_FORM_URLENCODED,
            MediaType.APPLICATION_JSON,
            MediaType.valueOf("application/*+json"),
            MediaType.MULTIPART_FORM_DATA
    );

    @ExceptionHandler
    @ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR) // Http Status Code 500
    public ResponseDTO handleException(Exception e, HttpServletRequest request) {
        String requestLog = StringUtils.EMPTY;
        if (request instanceof ContentCachingRequestWrapper) {
            requestLog = logRequest((ContentCachingRequestWrapper) request);
        }

        log.error("请求发生异常, {}", requestLog, e);
        return ResponseDTO.failedResponse().withErrorMessage("服务器开小差了");
    }

    private String logRequest(ContentCachingRequestWrapper request) {
        StringBuilder sb = new StringBuilder(1024)
                .append("request:").append(request.getMethod()).append(" ")
                .append(request.getRequestURI()).append(LINE_SEPARATOR);
        byte[] content = request.getContentAsByteArray();
        if (content.length > 0 && (!MediaType.APPLICATION_FORM_URLENCODED.includes(MediaType.valueOf(request.getContentType())))) {
            logContent(content, request.getContentType(), request.getCharacterEncoding(), "requestBody:", sb);
        } else {
            String paramString = StringUtils.EMPTY;
            Map<String, String[]> parameterMap = request.getParameterMap();
            if (MapUtils.isNotEmpty(parameterMap)) {
                List<String> pairs = Lists.newArrayList();
                parameterMap.forEach((name, values) -> {
                    for (String value : values) {
                        pairs.add(name + "=" + StringUtils.trimToEmpty(value));
                    }
                });
                paramString = Joiner.on("&").join(pairs);
            }

            if (StringUtils.equals(request.getContentType(), MediaType.APPLICATION_FORM_URLENCODED_VALUE)) {
                try {
                    paramString = URLDecoder.decode(paramString, request.getCharacterEncoding());
                } catch (UnsupportedEncodingException e) {
                }
            }
            sb.append("requestParams:").append(paramString).append(LINE_SEPARATOR);
        }
        return StringUtils.trimToEmpty(sb.toString());
    }

    private void logContent(byte[] content, String contentType, String contentEncoding, String prefix, StringBuilder sb) {
        sb.append(prefix);
        MediaType mediaType = MediaType.valueOf(contentType);
        boolean visible = VISIBLE_TYPES.stream().anyMatch(visibleType -> visibleType.includes(mediaType));
        if (visible) {
            try {
                String contentString = new String(content, contentEncoding);
                sb.append(contentString).append(LINE_SEPARATOR);
            } catch (UnsupportedEncodingException e) {
                sb.append("[" + content.length + " bytes content]").append(LINE_SEPARATOR);
            }
        } else {
            sb.append("[" + content.length + " bytes content]").append(LINE_SEPARATOR);
        }
    }

}

拓展学习

回到最初的想法：只要拿到request，就能将请求参数打印出来，我们实验之后，确实是能拿到request。但是，为什么在参数里写个request，Spring MVC就能把request给注入进来？在参数里写response，又能拿到吗？更一般地，这儿到底能写什么参数，能够让Spring MVC帮我们注入呢？

@ExceptionHandler
@ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR)
public ResponseDTO handleException(Exception e, HttpServletRequest request) {
    // 
}

上篇文章提到，调用异常处理方法的入口是

protected ModelAndView doResolveHandlerMethodException(HttpServletRequest request,
        HttpServletResponse response, HandlerMethod handlerMethod, Exception exception) {
    
    // ...
    exceptionHandlerMethod.invokeAndHandle(webRequest, mavContainer, exception, handlerMethod);
    // ...
}

我们看到，exception, handlerMethod被当作参数传入了providedArgs数组中

public void invokeAndHandle(ServletWebRequest webRequest, ModelAndViewContainer mavContainer,
            Object... providedArgs) throws Exception {

    Object returnValue = invokeForRequest(webRequest, mavContainer, providedArgs);
    // ...


public Object invokeForRequest(NativeWebRequest request, ModelAndViewContainer mavContainer,
            Object... providedArgs) throws Exception {

    Object[] args = getMethodArgumentValues(request, mavContainer, providedArgs);
    // ...


private Object[] getMethodArgumentValues(NativeWebRequest request, ModelAndViewContainer mavContainer,
        Object... providedArgs) throws Exception {

    MethodParameter[] parameters = getMethodParameters();
    Object[] args = new Object[parameters.length];
    for (int i = 0; i < parameters.length; i++) {
        MethodParameter parameter = parameters[i];
        parameter.initParameterNameDiscovery(this.parameterNameDiscoverer);
        // 重点看这一行
        args[i] = resolveProvidedArgument(parameter, providedArgs);
        if (args[i] != null) {
            continue;
        }
        if (this.argumentResolvers.supportsParameter(parameter)) {
            try {
                // 重点看这一行
                args[i] = this.argumentResolvers.resolveArgument(
                        parameter, mavContainer, request, this.dataBinderFactory);
                continue;
            }
            catch (Exception ex) {
                if (logger.isDebugEnabled()) {
                    logger.debug(getArgumentResolutionErrorMessage("Failed to resolve", i), ex);
                }
                throw ex;
            }
        }
        if (args[i] == null) {
            throw new IllegalStateException("Could not resolve method parameter at index " +
                    parameter.getParameterIndex() + " in " + parameter.getMethod().toGenericString() +
                    ": " + getArgumentResolutionErrorMessage("No suitable resolver for", i));
        }
    }
    return args;
}

先来看args[i] = resolveProvidedArgument(parameter, providedArgs);

private Object resolveProvidedArgument(MethodParameter parameter, Object... providedArgs) {
    if (providedArgs == null) {
        return null;
    }
    for (Object providedArg : providedArgs) {
        if (parameter.getParameterType().isInstance(providedArg)) {
            return providedArg;
        }
    }
    return null;
}

只要方法参数类型是providedArg(exception, handlerMethod)的实例，就返回解析成功，这就解释了，为什么能在方法参数里写Exception类型的参数，且会被注入相应的异常实例。此外，通过此处知道，我们还可以拿到handlerMethod的实例，即抛出异常的Controller Method，如此，我们就可以拿到相应的方法或其上的注解，基于此我们可以扩展很多玩法。

再接着看args[i] = this.argumentResolvers.resolveArgument( parameter, mavContainer, request, this.dataBinderFactory);

public Object resolveArgument(MethodParameter parameter, ModelAndViewContainer mavContainer,
        NativeWebRequest webRequest, WebDataBinderFactory binderFactory) throws Exception {
        
    HandlerMethodArgumentResolver resolver = getArgumentResolver(parameter);
    if (resolver == null) {
        throw new IllegalArgumentException("Unknown parameter type [" + parameter.getParameterType().getName() + "]");
    }
    return resolver.resolveArgument(parameter, mavContainer, webRequest, binderFactory);
}

resolver(HandlerMethodArgumentResolver)有很多实现类，此处按下不表，先直接进到ServletRequestMethodArgumentResolver#resolveArgument

public Object resolveArgument(MethodParameter parameter, ModelAndViewContainer mavContainer,
        NativeWebRequest webRequest, WebDataBinderFactory binderFactory) throws Exception {
    Class<?> paramType = parameter.getParameterType();
    if (WebRequest.class.isAssignableFrom(paramType)) {
        if (!paramType.isInstance(webRequest)) {
            throw new IllegalStateException(
                    "Current request is not of type [" + paramType.getName() + "]: " + webRequest);
        }
        return webRequest;
    }
    HttpServletRequest request = webRequest.getNativeRequest(HttpServletRequest.class);
    
    // 只要参数类型是ServletRequest、MultipartRequest或者它们的子类，就获取nativeRequest并返回
    if (ServletRequest.class.isAssignableFrom(paramType) || MultipartRequest.class.isAssignableFrom(paramType)) {
        Object nativeRequest = webRequest.getNativeRequest(paramType);
        if (nativeRequest == null) {
            throw new IllegalStateException(
                    "Current request is not of type [" + paramType.getName() + "]: " + request);
        }
        return nativeRequest;
    }
    // ...

通过这儿的代码，我们可以看出Spring MVC是如何寻找并注入request的。

接下来，分析更一般化地，异常处理方法支持什么类型的参数
ExceptionHandlerExceptionResolver在Bean初始化的时候，回调afterPropertiesSet方法，除了初始化上篇中提到的exceptionHandlerAdviceCache，还初始化了argumentResolvers和returnValueHandlers

public void afterPropertiesSet() {
    // Do this first, it may add ResponseBodyAdvice beans
    initExceptionHandlerAdviceCache();

    if (this.argumentResolvers == null) {
        // 这儿获取了默认参数解析器
        List<HandlerMethodArgumentResolver> resolvers = getDefaultArgumentResolvers();
        this.argumentResolvers = new HandlerMethodArgumentResolverComposite().addResolvers(resolvers);
    }
    if (this.returnValueHandlers == null) {
        List<HandlerMethodReturnValueHandler> handlers = getDefaultReturnValueHandlers();
        this.returnValueHandlers = new HandlerMethodReturnValueHandlerComposite().addHandlers(handlers);
    }
}

默认的参数解析器有三类

  1. 基于注解
  • SessionAttribute
    • 参数被@SessionAttribute注解
  • RequestAttribute
    • 参数被@RequestAttribute注解
  1. 基于类型
  • ServletRequest
    • 参数类型是WebRequest或其子类
    • 参数类型是ServletRequest或其子类
    • 参数类型是MultipartRequest或其子类
    • 参数类型是HttpSession或其子类
    • 参数类型是Principal或其子类
    • 参数类型是InputStream或其子类
    • 参数类型是Reader或其子类
    • 参数类型是HttpMethod
    • 参数类型是Locale
    • 参数类型是TimeZone
    • 参数类型是ZoneId(Since JDK1.8)
  • ServletResponse
    • 参数类型是ServletResponse或其子类
    • 参数类型是OutputStream或其子类
    • 参数类型是Writer或其子类
  • RedirectAttributes
    • 参数类型是RedirectAttributes或其子类
  • Model
    • 参数类型是Model或其子类
  1. 自定义
protected List<HandlerMethodArgumentResolver> getDefaultArgumentResolvers() {
    List<HandlerMethodArgumentResolver> resolvers = new ArrayList<HandlerMethodArgumentResolver>();

    // Annotation-based argument resolution
    resolvers.add(new SessionAttributeMethodArgumentResolver());
    resolvers.add(new RequestAttributeMethodArgumentResolver());
    
    // Type-based argument resolution
    resolvers.add(new ServletRequestMethodArgumentResolver());
    resolvers.add(new ServletResponseMethodArgumentResolver());
    resolvers.add(new RedirectAttributesMethodArgumentResolver());
    resolvers.add(new ModelMethodProcessor());
    
    // Custom arguments
    if (getCustomArgumentResolvers() != null) {
        resolvers.addAll(getCustomArgumentResolvers());
    }
    return resolvers;
}

public boolean supportsParameter(MethodParameter parameter) {
    Class<?> paramType = parameter.getParameterType();
    return (WebRequest.class.isAssignableFrom(paramType) ||
            ServletRequest.class.isAssignableFrom(paramType) ||
            MultipartRequest.class.isAssignableFrom(paramType) ||
            HttpSession.class.isAssignableFrom(paramType) ||
            Principal.class.isAssignableFrom(paramType) ||
            InputStream.class.isAssignableFrom(paramType) ||
            Reader.class.isAssignableFrom(paramType) ||
            HttpMethod.class == paramType ||
            Locale.class == paramType ||
            TimeZone.class == paramType ||
            "java.time.ZoneId".equals(paramType.getName()));
}

简单总结一下，异常处理方法中的参数支持两大类型

  1. providedArgs: exception, handlerMethod
  2. argumentResolvers: 基于注解、基于类型、自定义

总结

本篇开篇讨论了统一日志规范的重要性，接着抛出一个问题：引入统一异常处理方案后，如何打印请求上下文？答案是在异常处理方法中引入Request，通过Request拿到请求信息。但随之而来的问题是，普通的HttpServletRequest无法二次读取请求体信息，因此又引入了ContentCachingRequestWrapper，并介绍了其工作原理，通过配置Filter的方式使其生效，此时再配合GlobalExceptionHandler就可以打印请求上下文信息。最后，拓展开来，介绍了异常处理方法中支持哪些类型的参数，为以后实现更灵活的功能提供可能性。

导读：Spring MVC统一异常处理及原理分析

©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 203,362评论 5赞 477
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 85,330评论 2赞 381
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 150,247评论 0赞 337
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 54,560评论 1赞 273
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 63,580评论 5赞 365
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 48,569评论 1赞 281
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 37,929评论 3赞 395
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,587评论 0赞 258
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 40,840评论 1赞 297
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,596评论 2赞 321
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,678评论 1赞 329
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,366评论 4赞 318
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 38,945评论 3赞 307
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,929评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,165评论 1赞 259
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 43,271评论 2赞 349
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,403评论 2赞 342

推荐阅读更多精彩内容