Spring MVC exception - Invoking request method resulted in exception : public static native long java.lang.System.currentTimeMillis()

Question

I just saw this exception a number of times in my log files:

Invoking request method resulted in exception : public static native long java.lang.System.currentTimeMillis()

java.lang.IllegalArgumentException: Invalid handler method return value: 1302697287376
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerExceptionResolver.getModelAndView(AnnotationMethodHandlerExceptionResolver.java:410)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerExceptionResolver.doResolveException(AnnotationMethodHandlerExceptionResolver.java:140)
    at org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver.resolveException(AbstractHandlerExceptionResolver.java:136)
    at org.springframework.web.servlet.DispatcherServlet.processHandlerException(DispatcherServlet.java:987)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:811)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:719)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:644)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:549)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:621)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:78)
    at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:154)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:240)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:164)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:462)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:562)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:395)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:250)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:188)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:166)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:302)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:636)

Yes, none of my code is there. What the exception means is that a handler method has returned a long number, but it can only return a limited set of types.

What I don't realize is how was the System.currentTimeMillis() realized as a handler method?

Answer 1

** Update: This has been fixed in Spring 3.1.2 **

I believe this is indeed caused by a race condition. I've created a Jira issue for it, where I've tried to explain what happens: https://jira.springsource.org/browse/SPR-9138

Here's an excerpt of the explanation from the jira issue:

private Method findBestExceptionHandlerMethod(Object handler, final Exception thrownException) {
    //T1 and T2 enters method
    final Class<?> handlerType = ClassUtils.getUserClass(handler);
    final Class<? extends Throwable> thrownExceptionType = thrownException.getClass();
    Method handlerMethod = null;

    Map<Class<? extends Throwable>, Method> handlers = exceptionHandlerCache.get(handlerType);
    //Timing makes (handlers==null) for T1 (handler != null) for T2
    if (handlers != null) {
        handlerMethod = handlers.get(thrownExceptionType);
        //handlerMethod is still null for T2
        if (handlerMethod != null) {
            return (handlerMethod == NO_METHOD_FOUND ? null : handlerMethod);
        }
    }
    else {
        //T1 does this, the hashmap created here is read by T2 in if-test above matching this else block
        handlers = new ConcurrentHashMap<Class<? extends Throwable>, Method>();
        exceptionHandlerCache.put(handlerType, handlers);
    }

    //handlers is empty for both T1 and T2, the two threads' resolverMethod variables will reference the same
    // ConcurrentHashMap instance
    final Map<Class<? extends Throwable>, Method> resolverMethods = handlers;

    //This block does not find a match for the exception
    ReflectionUtils.doWithMethods(handlerType, new ReflectionUtils.MethodCallback() {
        public void doWith(Method method) {
            method = ClassUtils.getMostSpecificMethod(method, handlerType);
            List<Class<? extends Throwable>> handledExceptions = getHandledExceptions(method);
            for (Class<? extends Throwable> handledException : handledExceptions) {
                if (handledException.isAssignableFrom(thrownExceptionType)) {
                    if (!resolverMethods.containsKey(handledException)) {
                        resolverMethods.put(handledException, method);
                    } else {
                        Method oldMappedMethod = resolverMethods.get(handledException);
                        if (!oldMappedMethod.equals(method)) {
                            throw new IllegalStateException(
                                    "Ambiguous exception handler mapped for " + handledException + "]: {" +
                                            oldMappedMethod + ", " + method + "}.");
                        }
                    }
                }
            }
        }
    });
    //T1 finds no match and puts NO_METHOD_FOUND in cache and returns null
    // When T2 hits this line resolverMethods for T2 reference the same Map that T1 just put the NO_METHOD_FOUND
    // as a result getBestMatchingMethod will return NO_SUCH_METHOD_FOUND (System.timeMillis()) which will be invoked
    // by the doResolveException further up the callstack.
    handlerMethod = getBestMatchingMethod(resolverMethods, thrownException);
    handlers.put(thrownExceptionType, (handlerMethod == null ? NO_METHOD_FOUND : handlerMethod));
    return handlerMethod;
}

Answer 2

They use System.currentTimeMillis() as a dummy value in a cache of exception handler methods:

// dummy method placeholder
private static final Method NO_METHOD_FOUND = ClassUtils.getMethodIfAvailable(System.class, "currentTimeMillis", null);

And it leaks without check under contention (if inserted by another thread between (1) and (2)). Or perhaps even without contention due to difference between thrownExceptionType and closestMatch:

private Method findBestExceptionHandlerMethod(Object handler, final Exception thrownException) {
    ...
    Map<Class<? extends Throwable>, Method> handlers = exceptionHandlerCache.get(handlerType);

    if (handlers != null) {
        handlerMethod = handlers.get(thrownExceptionType); // 1
        if (handlerMethod != null) {
            return (handlerMethod == NO_METHOD_FOUND ? null : handlerMethod);
        }
    }
    ...
    final Map<Class<? extends Throwable>, Method> resolverMethods = handlers;   
    ...
    handlerMethod = getBestMatchingMethod(resolverMethods, thrownException); // 2
    handlers.put(thrownExceptionType, (handlerMethod == null ? NO_METHOD_FOUND : handlerMethod));
    return handlerMethod;
}

private Method getBestMatchingMethod(
        Map<Class<? extends Throwable>, Method> resolverMethods, Exception thrownException) {

    if (!resolverMethods.isEmpty()) {
        Class<? extends Throwable> closestMatch =
                ExceptionDepthComparator.findClosestMatch(resolverMethods.keySet(), thrownException);
        return resolverMethods.get(closestMatch);
    }
    else {
        return null;
    }
}

See AnnotationMethodHandlerExceptionResolver.java.