[
https://issues.apache.org/jira/browse/CAMEL-10024?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15319134#comment-15319134
]
Niels Ull Harremoes commented on CAMEL-10024:
---------------------------------------------
On further analysis, this is not trivial. :-(
I have written the following unit test to demonstrate the issue. Even with the
fix I suggested, I still get this error:
{code}
java.lang.IllegalStateException: handler cannot be set while the service is
active.
at
org.apache.mina.core.service.AbstractIoService.setHandler(AbstractIoService.java:357)
at
org.apache.camel.component.mina2.Mina2Producer.openConnection(Mina2Producer.java:267)
at
org.apache.camel.component.mina2.Mina2Producer.doProcess(Mina2Producer.java:125)
at
org.apache.camel.component.mina2.Mina2Producer.process(Mina2Producer.java:112)
at
org.apache.camel.component.mina2.Mina2DisconnectTest.testCloseSessionWhenCompleteManyTimes(Mina2DisconnectTest.java:56)
{code}
Here is the test:
{code}
public class Mina2DisconnectRaceConditionTest extends BaseMina2Test {
/**
* This is a test for issue CAMEL-10024 - the closing must complete before
we return from the producer
* @throws Exception
*/
@Test
public void testCloseSessionWhenCompleteManyTimes() throws Exception {
final String endpointUri =
String.format("mina2:tcp://localhost:%1$s?sync=true&textline=true&disconnect=true&minaLogger=true",
getPort());
Mina2Producer producer = (Mina2Producer)
context.getEndpoint(endpointUri).createProducer();
// Access session to check that the session is really closed
Field field = producer.getClass().getDeclaredField("session");
field.setAccessible(true);
for(int i = 0; i < 1000; i++) {
System.out.println(i);
Exchange e = new DefaultExchange(context,ExchangePattern.InOut);
e.getIn().setBody("Chad");
producer.process(e);
final IoSession ioSession = (IoSession) field.get(producer);
assertTrue(ioSession.getCloseFuture().isDone());
Object out = e.getOut().getBody();
assertEquals("Bye Chad", out);
}
}
@Override
protected RouteBuilder createRouteBuilder() throws Exception {
return new RouteBuilder() {
public void configure() throws Exception {
from(String.format("mina2:tcp://localhost:%1$s?sync=true&textline=true&disconnect=true",
getPort())).process(new Processor() {
public void process(Exchange exchange) throws Exception {
String body = exchange.getIn().getBody(String.class);
exchange.getOut().setBody("Bye " + body);
}
});
}
};
}
}
{code}
> Race condition in Mina2Producer/Mina2Consumer when closing connections with
> disconnect=true
> -------------------------------------------------------------------------------------------
>
> Key: CAMEL-10024
> URL: https://issues.apache.org/jira/browse/CAMEL-10024
> Project: Camel
> Issue Type: Bug
> Components: camel-mina2
> Affects Versions: 2.17.1
> Environment: Tested on Windows using Java 1.8.0_91
> Reporter: Niels Ull Harremoes
>
> There is a race condition in the Mina2Producer when trying to close
> connections after use by setting disconnect=true or
> setting CamelMina2CloseSessionWhenComplete=true.
> Connections will not be fully closed in the method maybeDisconnectOnDone.
> The call to session.close(true) returns a CloseFuture - one must await this
> to ensure the session is really closed.
> In the current implementation, there is no await on the CloseFuture. This
> means that the producer will be returned to the pool before the session is
> closed. If the next call comes right after, it is very likely that it will
> get the same producer and that the session will suddenly be closed while in
> use, leading to errors like
> ExchangeTimedOutException: The OUT message was not received within 30000 ms
> or
> java.lang.IllegalStateException: handler cannot be set while the service is
> active.
> The fix is trivial - just change line 221 in Mina2Producer.java from
> {code:java}
> session.close(true);
> {code}
> to
> {code:java}
> long timeout = getEndpoint().getConfiguration().getTimeout();
> CloseFuture closeFuture = session.close(true);
> closeFuture.awaitUninterruptibly(timeout, TimeUnit.MILLISECONDS);
> {code}
> But the unit testing might be more complex.
> There might be a similar issue in Mina2Consumer - but I could not provoke it
> as easily.
> Here is a small program demonstrating the problem - on my system it will fail
> within the first 50 iterations. When looking at the debug log, it is clear
> that the connections are closed too late - after the next iteration has
> started.
> {code:java}
> import org.apache.camel.*;
> import org.apache.camel.builder.RouteBuilder;
> import org.apache.camel.impl.DefaultCamelContext;
> import org.slf4j.*;
> /**
> * Demonstrating race condition
> */
> public class Main {
> public static void main(String[] args) throws Exception {
>
> System.setProperty("org.slf4j.simpleLogger.log.org.apache.camel.component.mina2.Mina2Producer",
> "trace");
>
> System.setProperty("org.slf4j.simpleLogger.log.org.apache.mina.filter.logging.LoggingFilter",
> "trace");
>
> Logger logger = LoggerFactory.getLogger(Main.class);
> CamelContext context = new DefaultCamelContext();
> context.addRoutes(new RouteBuilder() {
> @Override
> public void configure() throws Exception {
>
> from("mina2:tcp://localhost:20000?sync=true").setBody(simple("Hello
> ${in.body}"));
> }
> });
> ProducerTemplate producerTemplate = context.createProducerTemplate();
> context.start();
> try {
> for (int i = 0; i < 10000; i++) {
> logger.info("---- Call # " + i);
> String result = (String)
> producerTemplate.requestBody("mina2:tcp://localhost:20000?disconnect=true&timeout=1000&sync=true&minaLogger=true",
> "world " + i);
> logger.info("---- End call # " + i + ": " + result);
> }
> } finally {
> context.stop();
> }
> }
> }
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
