Spring boot + tomcat 8.5 + mongoDB, AsyncRequestTimeoutException

Question

I have created a spring boot web application and deployed war of the same to tomcat container. The application connects to mongoDB using Async connections. I am using mongodb-driver-async library for that.

At startup everything works fine. But as soon as load increases, It shows following exception in DB connections:

org.springframework.web.context.request.async.AsyncRequestTimeoutException: null
        at org.springframework.web.context.request.async.TimeoutDeferredResultProcessingInterceptor.handleTimeout(TimeoutDeferredResultProcessingInterceptor.java:42)
        at org.springframework.web.context.request.async.DeferredResultInterceptorChain.triggerAfterTimeout(DeferredResultInterceptorChain.java:75)
        at org.springframework.web.context.request.async.WebAsyncManager$5.run(WebAsyncManager.java:392)
        at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.onTimeout(StandardServletAsyncWebRequest.java:143)
        at org.apache.catalina.core.AsyncListenerWrapper.fireOnTimeout(AsyncListenerWrapper.java:44)
        at org.apache.catalina.core.AsyncContextImpl.timeout(AsyncContextImpl.java:131)
        at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:157)

I am using following versions of software:

1. Spring boot -> 1.5.4.RELEASE
2. Tomcat (installed as standalone binary) -> apache-tomcat-8.5.37
3. Mongo DB version: v3.4.10
4. mongodb-driver-async: 3.4.2

As soon as I restart the tomcat service, everything starts working fine.

Please help, what could be the root cause of this issue.

P.S.: I am using DeferredResult and CompletableFuture to create Async REST API.

I have also tried using spring.mvc.async.request-timeout in application and configured asynTimeout in tomcat. But still getting same error.

Stew

You could try to set spring.mvc.async.request-timeout to a high value and see if this helps. Do you know which operation does take long? – Halyard

Yes, I have tried that already, But it doesn't help – Stew

And do you know which operations is causing the problem? – Halyard

In all operations – Stew

Could this be related to this thread? #39856698 – Dramatic

I have already tried this, but no success – Stew

Answer 1

It's probably obvious that Spring is timing out your requests and throwing AsyncRequestTimeoutException, which returns a 503 back to your client.

Now the question is, why is this happening? There are two possibilities.

1. These are legitimate timeouts. You mentioned that you only see the exceptions when the load on your server increases. So possibly your server just can't handle that load and its performance has degraded to the point where some requests can't complete before Spring times them out.

2. The timeouts are caused by your server failing to send a response to an asynchronous request due to a programming error, leaving the request open until Spring eventually times it out. It's easy for this to happen if your server doesn't handle exceptions well. If your server is synchronous, it's okay to be a little sloppy with exception handling because unhandled exceptions will propagate up to the server framework, which will send a response back to the client. But if you fail to handle an exception in some asynchronous code, that exception will be caught elsewhere (probably in some thread pool management code), and there's no way for that code to know that there's an asynchronous request waiting on the result of the operation that threw the exception.

It's hard to figure out what might be happening without knowing more about your application. But there are some things you could investigate.

First, try looking for resource exhaustion.

• Is the garbage collector running all the time?
• Are all CPUs pegged at 100%?
• Is the OS swapping heavily?
• If the database server is on a separate machine, is that machine showing signs of resource exhaustion?
• How many connections are open to the database? If there is a connection pool, is it maxed out?
• How many threads are running? If there are thread pools in the server, are they maxed out?

If something's at its limit then possibly it is the bottleneck that is causing your requests to time out.

Try setting spring.mvc.async.request-timeout to -1 and see what happens. Do you now get responses for every request, only slowly, or do some requests seem to hang forever? If it's the latter, that strongly suggests that there's a bug in your server that's causing it to lose track of requests and fail to send responses. (If setting spring.mvc.async.request-timeout appears to have no effect, then the next thing you should investigate is whether the mechanism you're using for setting the configuration actually works.)

A strategy that I've found useful in these cases is to generate a unique ID for each request and write the ID along with some contextual information every time the server either makes an asynchronous call or receives a response from an asynchronous call, and at various checkpoints within asynchronous handlers. If requests go missing, you can use the log information to figure out the request IDs and what the server was last doing with that request.

A similar strategy is to save each request ID into a map in which the value is an object that tracks when the request was started and what your server last did with that request. (In this case your server is updating this map at each checkpoint rather than, or in addition to, writing to the log.) You can set up a filter to generate the request IDs and maintain the map. If your filter sees the server send a 5xx response, you can log the last action for that request from the map.

Hope this helps!

Inflexed

+1 for the strategy using unique ID. Multi-threaded / app with async call are always hard to debug and thus very difficult to identify the problem area / root cause – Nonprofit

Thanks for marking this the right answer! What did you discover the issue to be? – Inflexed

Answer 2

Asynchroneus tasks are arranged in a queue(pool) which is processed in parallel depending on the number of threads allocated. Not all asynchroneus tasks are executed at the same time. Some of them are queued. In a such system getting AsyncRequestTimeoutException is normal behaviour.

If you are filling up the queues with asynchroneus tasks that are unable to execute under pressure. Increasing the timeout will only delay the problem. You should focus instead on the problem:

1. Reduce the execution time(through various optimizations) of asynchroneus task. This will relax the pooling of async tasks. It oviously requires coding.
2. Increase the number of CPUSs allocated in order to be able to run more efficiently the parallel tasks.
3. Increase the number of threads servicing the executor of the driver.

Mongo Async driver is using AsynchronousSocketChannel or Netty if Netty is found in the classpath. In order to increase the number of the worker threads servicing the async comunication you should use:

      MongoClientSettings.builder()
    .streamFactoryFactory(NettyStreamFactoryFactory(io.netty.channel.EventLoopGroup eventLoopGroup, 
io.netty.buffer.ByteBufAllocator allocator))
                       .build();

where eventLoopGroup would be io.netty.channel.nio.NioEventLoopGroup(int nThreads))

on the NioEventLoopGroup you can set the number of threads servicing your async comunication

Read more about Netty configuration here https://mongodb.github.io/mongo-java-driver/3.2/driver-async/reference/connecting/connection-settings/

Complicated