Need help troubleshooting async support enablement in Spring application with Tomcat

Question

Have a working Spring REST endpoint using Tomcat 7, running using JDK 1.7. Built using gradle, where build.gradle has dependencies on Spring libraries v4.1.6, and javax.servlet v3.0.1 amongst other things. Added a new method with a simplistic implementation to the @Controller class, which returns value of DeferredResult<String>. When I send a GET request to the endpoint and the new method is invoked, around the time it returns a value I see the following exception logged in server logs: (see further below for exception stack)

In the web.xml file (which gets built into my .war) there are 3-4 filters (including springSecurityFilterChain) and about 8 filters (one of which is for org.springframework.web.servlet.DispatcherServlet and with the url pattern /rest/* - which matches the URL for the GET request that fails - with HTTP error code 400). I've tried adding <async-supported>true</async-supported> to both the servlet and filter definitions, but this seems to have no visible effect.

Any tips on how to troubleshoot this would be much appreciated!

(might be worth noting that my simple hello-world Spring REST endpoint in a separate workspace, when deployed to the same version of Tomcat seemed to start working just fine after I added the to the one and only servlet definition in it's web.xml...)

java.lang.IllegalStateException: Async support must be enabled on a servlet and for all filters involved in async request processing. This is done in Java code using the Servlet API or by adding "<async-supported>true</async-supported>" to servlet and filter declarations in web.xml.
at org.springframework.util.Assert.state(Assert.java:385) ~[spring-core-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.startAsync(StandardServletAsyncWebRequest.java:103) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.context.request.async.WebAsyncManager.startAsyncProcessing(WebAsyncManager.java:422) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.context.request.async.WebAsyncManager.startDeferredResultProcessing(WebAsyncManager.java:402) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.DeferredResultMethodReturnValueHandler.handleReturnValue(DeferredResultMethodReturnValueHandler.java:49) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:71) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:126) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966) [spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:857) [spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:621) [servlet-api.jar:na]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842) [spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728) [servlet-api.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305) [catalina.jar:7.0.39]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) [catalina.jar:7.0.39]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:316) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:126) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:122) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:168) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:48) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.authentication.preauth.AbstractPreAuthenticatedProcessingFilter.doFilter(AbstractPreAuthenticatedProcessingFilter.java:116) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:53) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:91) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:152) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:213) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:176) [spring-security-web-4.0.0.RELEASE.jar:na]
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) [catalina.jar:7.0.39]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) [catalina.jar:7.0.39]
at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:399) [urlrewritefilter-4.0.4.jar:4.0.4]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) [catalina.jar:7.0.39]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) [catalina.jar:7.0.39]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222) [catalina.jar:7.0.39]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123) [catalina.jar:7.0.39]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472) [catalina.jar:7.0.39]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) [catalina.jar:7.0.39]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99) [catalina.jar:7.0.39]
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:947) [catalina.jar:7.0.39]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) [catalina.jar:7.0.39]
at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:178) [logback-access-1.0.13.jar:na]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408) [catalina.jar:7.0.39]
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1009) [tomcat-coyote.jar:7.0.39]
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589) [tomcat-coyote.jar:7.0.39]
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312) [tomcat-coyote.jar:7.0.39]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_79]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_79]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_79]

The web.xml currently looks like this (I've temporarily commented out springSecurity filter, by trying to make it as bare-bones as possible):

<?xml version="1.0" encoding="UTF-8"?>
<web-app xmlns="http://java.sun.com/xml/ns/javaee"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd"
version="3.0">

<display-name>XXX</display-name>

<resource-ref>
    <res-ref-name>jdbc/server</res-ref-name>
    <res-type>javax.sql.DataSource</res-type>
</resource-ref>
<resource-ref>
    <res-ref-name>jdbc/serverXA</res-ref-name>
    <res-type>javax.sql.DataSource</res-type>
</resource-ref>
<resource-ref>
    <res-ref-name>jms/serverXA</res-ref-name>
    <res-type>javax.jms.ConnectionFactory</res-type>
</resource-ref>

<listener>
    <listener-class>
        org.springframework.web.context.ContextLoaderListener
    </listener-class>
</listener>

<context-param>
    <param-name>contextConfigLocation</param-name>
    <param-value>
        /WEB-INF/config/web-application-config.xml
    </param-value>
</context-param>

<servlet>
    <servlet-name>Content Servlet</servlet-name>
    <servlet-class>org.apache.jasper.servlet.JspServlet</servlet-class>
    <init-param>
      <param-name>fork</param-name>
      <param-value>false</param-value>
    </init-param>
    <init-param>
      <param-name>xpoweredBy</param-name>
      <param-value>false</param-value>
    </init-param>
    <load-on-startup>3</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>Content Servlet</servlet-name>
    <url-pattern>/content/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>Resources Servlet</servlet-name>
    <servlet-class>org.springframework.web.servlet.ResourceServlet</servlet-class>
    <load-on-startup>0</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>Resources Servlet</servlet-name>
    <url-pattern>/resources/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>WebMVC Logos</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/webmvc-logos.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>WebMVC Logos</servlet-name>
    <url-pattern>/logos/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>WebMVC Downloads</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/webmvc-downloads.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>WebMVC Downloads</servlet-name>
    <url-pattern>/downloads/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>WebMVC WebApp</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/webmvc-servlet-config.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>WebMVC WebApp</servlet-name>
    <url-pattern>/webapp/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>Remoting Dispatcher</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/remoting-servlet-config.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>Remoting Dispatcher</servlet-name>
    <url-pattern>/remoting/*</url-pattern>
</servlet-mapping>

<servlet>
    <servlet-name>WebMVC REST</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/webmvc-rest.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
    <async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>WebMVC REST</servlet-name>
    <url-pattern>/rest/*</url-pattern>
</servlet-mapping>

<session-config>
    <session-timeout>10</session-timeout>
</session-config>

<servlet>
    <servlet-name>repository</servlet-name>
    <servlet-class>org.springframework.web.servlet.DispatcherServlet</servlet-class>
    <init-param>
        <param-name>contextConfigLocation</param-name>
        <param-value>/WEB-INF/config/repository-config.xml</param-value>
    </init-param>
    <load-on-startup>1</load-on-startup>
<async-supported>true</async-supported>
</servlet>

<servlet-mapping>
    <servlet-name>repository</servlet-name>
    <url-pattern>/repository/*</url-pattern>
</servlet-mapping>

</web-app>

I have the same problem, as far as I know tomcat has no good support for async. I hope you have used NIOConnector, that is required for async. — We are Borg
Following your suggestion I've tried editing server.xml for Tomcat and changing the protocol for the 8080 port connector to NIO one, but that didn't seem to make a difference. Also, as I mentioned, the simpler 'hello-world'-style Spring REST project with async-supported flag set for a servlet seems to work fine in the same version of Tomcat for me... — Greg B
I meant NIO connector is required for async for tomcat, this is not that problem. Anyways, edit your post and put your web.xml there. — We are Borg
Ok, what the error means is for all the filters you need to add async supported, but I can see it only for one. If you are using any IDE, you try adding within each sub part as asyn-supported is true, if it is not allowed, IDE will complain, remove it. If IDE doesn't complain, let it stay. Then restart the server and let me know. — We are Borg
As I mentioned in my original post, I've already tried adding it to all filters and servlet definitions... didn't seem to make a difference, I'm afraid. — Greg B

Tzvetan Stefanov Tzvetan Stefanov · Accepted Answer · 2017-01-26T10:42:02

ch.qos.logback.access.tomcat.LogbackValve is configured for synchronous processing by default.

So it should be configured with enabled async support.

Here is one example:

@Bean
public EmbeddedServletContainerFactory servletContainer() {

  TomcatEmbeddedServletContainerFactory tomcat = new TomcatEmbeddedServletContainerFactory();

  LogbackValve logbackValve = new LogbackValve();
  logbackValve.setAsyncSupported(true);
  logbackValve.setFilename(logbackAccessFile);

  tomcat.addContextValves(logbackValve);
  return tomcat;
}

Need help troubleshooting async support enablement in Spring application with Tomcat

1 Answers