camel-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Niels Ull Harremoes (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CAMEL-10024) Race condition in Mina2Producer/Mina2Consumer when closing connections with disconnect=true
Date Tue, 07 Jun 2016 08:01:21 GMT

     [ https://issues.apache.org/jira/browse/CAMEL-10024?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Niels Ull Harremoes updated CAMEL-10024:
----------------------------------------
    Description: 
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:
{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++) {
                final String body = "world " + i;
                logger.info("---- Call # " + i);
                String result = (String) producerTemplate.requestBody("mina2:tcp://localhost:20000?disconnect=true&timeout=1000&sync=true&minaLogger=true",
body);
                logger.info("---- End call # " + i);
                assert result != null && result.equals("Hello " + body);
            }
        } finally {
            context.stop();
        }
    }
}
{code}



  was:
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 liine 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.

Here is a small program demonstrating the problem - on my system it will fail within the first
50 iterations:
{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++) {
                final String body = "world " + i;
                logger.info("---- Call # " + i);
                String result = (String) producerTemplate.requestBody("mina2:tcp://localhost:20000?disconnect=true&timeout=1000&sync=true&minaLogger=true",
body);
                logger.info("---- End call # " + i);
                assert result != null && result.equals("Hello " + body);
            }
        } finally {
            context.stop();
        }
    }
}
{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:
> {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++) {
>                 final String body = "world " + i;
>                 logger.info("---- Call # " + i);
>                 String result = (String) producerTemplate.requestBody("mina2:tcp://localhost:20000?disconnect=true&timeout=1000&sync=true&minaLogger=true",
body);
>                 logger.info("---- End call # " + i);
>                 assert result != null && result.equals("Hello " + body);
>             }
>         } finally {
>             context.stop();
>         }
>     }
> }
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message