Hi, I think I may have run into a potential issue with camel-ahc. I've narrowed it down to a very specific scenario - a combination of re-using the same ahc component in combination with using split().parallelProcessing() EIP. Tested with camel 2.14.1 and 2.14.0.
I'll try and demonstrate in a simple route: List<String> list = Arrays.asList("alice", "bob", "charles", "david", "edward"); from("timer://foo?repeatCount=1") .setBody(constant("someMainRouteContent")) .to("direct:fetch") // [1] .setBody(constant(list)) .split(body()).parallelProcessing() // [2] .log("processing ${body}") .to("direct:fetch") // [3] .end() .log("and back to main processing") .end(); from("direct:fetch") .log("making http request for ${body}") .to("ahc:http://localhost:8765/rest/test") .log("returned from http request for ${body}") .end(); Note: 1. The routes share the same AHC component [1, 3] (i.e. common set of ahc worker threads). 2. The ahc worker thread will continue processing synchronously between [1] and [2],until the point the split() parallel thread pool takes over. On an http response, the ahc worker thread will continue processing synchronouslyas expected. 3. The above will result in a timeout exception for one of the split exchanges (irrespective of the size of the list), and the route never completes. java.util.concurrent.TimeoutException: Request timeout of 60000 ms at com.ning.http.client.providers.netty.timeout.TimeoutTimerTask.expire(TimeoutTimerTask.java:43) at com.ning.http.client.providers.netty.timeout.RequestTimeoutTimerTask.run(RequestTimeoutTimerTask.java:41) at org.jboss.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:556) at org.jboss.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:632) at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:369) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at java.lang.Thread.run(Thread.java:722) Log output for the above route is attached. Having two separate ahc endpoints (i.e. with separate thread pools), or without parallel processing in the split EIP, then the above works fine. Any thoughts? Kind Regards, Elvio
13:53:09.757{UTC} [ main] DefaultCamelContext INFO Apache Camel 2.14.1 (CamelContext: camel-1) started in 0.949 seconds 13:53:10.772{UTC} [mel-1) thread #0 - timer://foo] route5 INFO making http request for someMainRouteContent 13:53:11.906{UTC} [ qtp202392075-23] route3 INFO Finished with rest request 13:53:11.930{UTC} [ New I/O worker #1] route5 INFO returned from http request for someMainRouteContent 13:53:11.940{UTC} [el (camel-1) thread #5 - Split] route4 INFO processing david 13:53:11.940{UTC} [el (camel-1) thread #6 - Split] route4 INFO processing edward 13:53:11.940{UTC} [el (camel-1) thread #6 - Split] route5 INFO making http request for edward 13:53:11.940{UTC} [el (camel-1) thread #1 - Split] route4 INFO processing alice 13:53:11.941{UTC} [el (camel-1) thread #1 - Split] route5 INFO making http request for alice 13:53:11.940{UTC} [el (camel-1) thread #2 - Split] route4 INFO processing bob 13:53:11.945{UTC} [el (camel-1) thread #2 - Split] route5 INFO making http request for bob 13:53:11.940{UTC} [el (camel-1) thread #4 - Split] route4 INFO processing charles 13:53:11.947{UTC} [el (camel-1) thread #4 - Split] route5 INFO making http request for charles 13:53:11.940{UTC} [el (camel-1) thread #5 - Split] route5 INFO making http request for david 13:53:12.944{UTC} [ qtp202392075-26] route3 INFO Finished with rest request 13:53:12.953{UTC} [ qtp202392075-21] route3 INFO Finished with rest request 13:53:12.953{UTC} [ New I/O worker #2] route5 INFO returned from http request for alice 13:53:12.954{UTC} [ qtp202392075-22] route3 INFO Finished with rest request 13:53:12.957{UTC} [ New I/O worker #4] route5 INFO returned from http request for charles 13:53:12.965{UTC} [ New I/O worker #3] route5 INFO returned from http request for bob 13:54:11.983{UTC} [ Hashed wheel timer #2] DefaultErrorHandler ERROR Failed delivery for (MessageId: ID-XXXX-52545-1422625988470-0-5 on ExchangeId: ID-XXXX-52545-1422625988470-0-8). Exhausted after delivery attempt: 1 caught: java.util.concurrent.TimeoutException: Request timeout of 60000 ms Message History --------------------------------------------------------------------------------------------------------------------------------------- RouteId ProcessorId Processor Elapsed (ms) [route4 ] [route4 ] [timer://foo?repeatCount=1 ] [ 61217] [route4 ] [log2 ] [log ] [ 0] [route4 ] [to4 ] [direct:fetch ] [ 60039] [route5 ] [log4 ] [log ] [ 0] [route5 ] [to5 ] [ahc:http://localhost:8765/rest/test ] [ 60039] Exchange --------------------------------------------------------------------------------------------------------------------------------------- Exchange[ Id ID-XXXX-52545-1422625988470-0-8 ExchangePattern InOnly Headers {Accept=*/*, breadcrumbId=ID-XXXX-52545-1422625988470-0-1, CamelHttpResponseCode=200, CamelRedelivered=false, CamelRedeliveryCounter=0, Content-Length=20, Content-Type=, firedTime=Fri Jan 30 13:53:10 GMT 2015, Server=Jetty(8.1.15.v20140411), Transfer-Encoding=chunked, User-Agent=NING/1.0} BodyType String Body edward ] Stacktrace --------------------------------------------------------------------------------------------------------------------------------------- java.util.concurrent.TimeoutException: Request timeout of 60000 ms at com.ning.http.client.providers.netty.timeout.TimeoutTimerTask.expire(TimeoutTimerTask.java:43) at com.ning.http.client.providers.netty.timeout.RequestTimeoutTimerTask.run(RequestTimeoutTimerTask.java:41) at org.jboss.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:556) at org.jboss.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:632) at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:369) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at java.lang.Thread.run(Thread.java:722)