Poison

SPR-11106

发表于

今天看了个小问题，即日志中出现了 OOM，但是发现没有对应的堆转储生成，导致 Agent 未监控到 OOM，仔细查看相关日志，发现是 Spring 的请求处理逻辑中对 Throwable 进行了 catch 然后包装了相关异常，该组应用使用的 Spring 版本为 5.3.20，相关源码位于 DispatcherServlet.java at v5.3.20:

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
/**
 * Process the actual dispatching to the handler.
 * <p>The handler will be obtained by applying the servlet's HandlerMappings in order.
 * The HandlerAdapter will be obtained by querying the servlet's installed HandlerAdapters
 * to find the first that supports the handler class.
 * <p>All HTTP methods are handled by this method. It's up to HandlerAdapters or handlers
 * themselves to decide which methods are acceptable.
 * @param request current HTTP request
 * @param response current HTTP response
 * @throws Exception in case of any kind of processing failure
 */
@SuppressWarnings("deprecation")
protected void doDispatch(HttpServletRequest request, HttpServletResponse response) throws Exception {
    HttpServletRequest processedRequest = request;
    HandlerExecutionChain mappedHandler = null;
    boolean multipartRequestParsed = false;

    WebAsyncManager asyncManager = WebAsyncUtils.getAsyncManager(request);

    try {
        ModelAndView mv = null;
        Exception dispatchException = null;

        try {
            processedRequest = checkMultipart(request);
            multipartRequestParsed = (processedRequest != request);

            // Determine handler for the current request.
            mappedHandler = getHandler(processedRequest);
            if (mappedHandler == null) {
                noHandlerFound(processedRequest, response);
                return;
            }

            // Determine handler adapter for the current request.
            HandlerAdapter ha = getHandlerAdapter(mappedHandler.getHandler());

            // Process last-modified header, if supported by the handler.
            String method = request.getMethod();
            boolean isGet = HttpMethod.GET.matches(method);
            if (isGet || HttpMethod.HEAD.matches(method)) {
                long lastModified = ha.getLastModified(request, mappedHandler.getHandler());
                if (new ServletWebRequest(request, response).checkNotModified(lastModified) && isGet) {
                    return;
                }
            }

            if (!mappedHandler.applyPreHandle(processedRequest, response)) {
                return;
            }

            // Actually invoke the handler.
            mv = ha.handle(processedRequest, response, mappedHandler.getHandler());

            if (asyncManager.isConcurrentHandlingStarted()) {
                return;
            }

            applyDefaultViewName(processedRequest, mv);
            mappedHandler.applyPostHandle(processedRequest, response, mv);
        }
        catch (Exception ex) {
            dispatchException = ex;
        }
        catch (Throwable err) {
            // As of 4.3, we're processing Errors thrown from handler methods as well,
            // making them available for @ExceptionHandler methods and other scenarios.
            dispatchException = new NestedServletException("Handler dispatch failed", err);
        }
        processDispatchResult(processedRequest, response, mappedHandler, mv, dispatchException);
    }
    catch (Exception ex) {
        triggerAfterCompletion(processedRequest, response, mappedHandler, ex);
    }
    catch (Throwable err) {
        triggerAfterCompletion(processedRequest, response, mappedHandler,
                new NestedServletException("Handler processing failed", err));
    }
    finally {
        if (asyncManager.isConcurrentHandlingStarted()) {
            // Instead of postHandle and afterCompletion
            if (mappedHandler != null) {
                mappedHandler.applyAfterConcurrentHandlingStarted(processedRequest, response);
            }
        }
        else {
            // Clean up any resources used by a multipart request.
            if (multipartRequestParsed) {
                cleanupMultipart(processedRequest);
            }
        }
    }
}

即在处理请求的过程中如果出现了 Error，则会被 65-69 行中的 catch (Throwable err) 捕获并包装为 NestedServletException，其注释也有说明：

As of 4.3, we’re processing Errors thrown from handler methods as well, making them available for @ExceptionHandler methods and other scenarios.

即从 4.3 开始，此处处理了 Error，并将其交给异常处理器或其他场景处理。但是这造成的问题为我们所需的堆转储文件并没生成，比如我们在全局异常处理器中仅进行了简单的处理并打印了日志，则会出现如下输出：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
class: org.springframework.web.util.NestedServletException
message: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: Java heap space
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1082)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)

即仅打印了 NestedServletException 异常，OOM 仅含有最基础的信息，最重要的 OOM 栈帧并未体现，导致问题难以排查。关于 NestedServletException 并未体现栈帧的问题，在该类的注释中也有说明，源码位于 NestedServletException.java at v5.3.20:

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
/**
 * Subclass of {@link ServletException} that properly handles a root cause in terms
 * of message and stacktrace, just like NestedChecked/RuntimeException does.
 *
 * <p>Note that the plain ServletException doesn't expose its root cause at all,
 * neither in the exception message nor in printed stack traces! While this might
 * be fixed in later Servlet API variants (which even differ per vendor for the
 * same API version), it is not reliably available on Servlet 2.4 (the minimum
 * version required by Spring 3.x), which is why we need to do it ourselves.
 *
 * <p>The similarity between this class and the NestedChecked/RuntimeException
 * class is unavoidable, as this class needs to derive from ServletException.
 *
 * @author Juergen Hoeller
 * @since 1.2.5
 * @see #getMessage
 * @see #printStackTrace
 * @see org.springframework.core.NestedCheckedException
 * @see org.springframework.core.NestedRuntimeException
 */
public class NestedServletException extends ServletException {

    /** Use serialVersionUID from Spring 1.2 for interoperability. */
    private static final long serialVersionUID = -5292377985529381145L;

    static {
        // Eagerly load the NestedExceptionUtils class to avoid classloader deadlock
        // issues on OSGi when calling getMessage(). Reported by Don Brown; SPR-5607.
        NestedExceptionUtils.class.getName();
    }


    /**
     * Construct a {@code NestedServletException} with the specified detail message.
     * @param msg the detail message
     */
    public NestedServletException(String msg) {
        super(msg);
    }

    /**
     * Construct a {@code NestedServletException} with the specified detail message
     * and nested exception.
     * @param msg the detail message
     * @param cause the nested exception
     */
    public NestedServletException(@Nullable String msg, @Nullable Throwable cause) {
        super(msg, cause);
    }


    /**
     * Return the detail message, including the message from the nested exception
     * if there is one.
     */
    @Override
    @Nullable
    public String getMessage() {
        return NestedExceptionUtils.buildMessage(super.getMessage(), getCause());
    }

}

可知 NestedServletException 继承自 ServletException，且注释特意提到：

Note that the plain ServletException doesn’t expose its root cause at all, neither in the exception message nor in printed stack traces! While this might be fixed in later Servlet API variants (which even differ per vendor for the same API version), it is not reliably available on Servlet 2.4 (the minimum version required by Spring 3.x), which is why we need to do it ourselves.

即 ServletException 无论是在其异常消息还是打印的栈帧中均未包含原始异常的信息，所以 NestedServletException 覆写了 getMessage 方法并包含了原始异常的信息，注意此处也仅包含了原始异常的信息，而未包含原始异常的栈帧，导致上面提到的 OOM 仅含有基础的提示信息。关于 4.3 引入的这一项改动可参考：@ExceptionHandler is able to process Error thrown from handler method · spring-projects/spring-framework@f6cb30b · GitHub。而关于为何要进行这样的改动，可以参考 Juergen Hoeller 在 SPR-13788 中的回复：

We tend to catch Throwable in quite a few places these days… in particular for close sequences where we’d like to continue with remaining clean-up steps if a particular resource close call failed for any reason.

Even OutOfMemoryError is not unrecoverable in that context, since it may for example happen when the JVM failed to allocate a large array… with enough free memory for further steps remaining afterwards, just with the layout not allowing for as large an array.

Since the log level is ‘error’ there anyway, what specifically did you miss? What would have been the actual benefit of letting the OOME through?

而关于是否 catch Throwable，其实是存在一些争议的，关于该问题的讨论可参考以下链接：

在当前的 Spring 实现之上，我们临时给出的解决方案如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
public class GlobalExceptionHandler implements HandlerExceptionResolver {

    @Override
    public ModelAndView resolveException(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
        Throwable rootCause = ex;
        if (ex instanceof NestedServletException && ((NestedServletException) ex).getRootCause() instanceof Error) {
            rootCause = ((NestedServletException) ex).getRootCause();
            if (rootCause instanceof OutOfMemoryError) {
                // Trigger heap dump generation
                throw (OutOfMemoryError) rootCause;
            }
        }

        // Log the rootCause stack trace...
    }

}

即在全局异常处理器中对 NestedServletException 做特殊处理，如果原始异常为 OOM，则直接抛出，以便生成堆转储文件供后续分析，如果是 Error 子类的其他错误，则进行对应日志记录。

Reference

@ExceptionHandler cannot handler java.lang.Error despite the annotation accept ? extends Throwable SPR-11106 · Issue #15732 · spring-projects/spring-framework · GitHub
NoClassDefFoundError