Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id CB610200B2B for ; Mon, 13 Jun 2016 09:17:22 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id CA186160A19; Mon, 13 Jun 2016 07:17:22 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 1CDAF160A3C for ; Mon, 13 Jun 2016 09:17:21 +0200 (CEST) Received: (qmail 25913 invoked by uid 500); 13 Jun 2016 07:17:21 -0000 Mailing-List: contact issues-help@camel.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@camel.apache.org Delivered-To: mailing list issues@camel.apache.org Received: (qmail 25891 invoked by uid 99); 13 Jun 2016 07:17:21 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 13 Jun 2016 07:17:21 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 140632C1F60 for ; Mon, 13 Jun 2016 07:17:21 +0000 (UTC) Date: Mon, 13 Jun 2016 07:17:21 +0000 (UTC) From: "Arno Noordover (JIRA)" To: issues@camel.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CAMEL-10024) Race condition in Mina2Producer/Mina2Consumer when closing connections with disconnect=true MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Mon, 13 Jun 2016 07:17:23 -0000 [ https://issues.apache.org/jira/browse/CAMEL-10024?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15326920#comment-15326920 ] Arno Noordover commented on CAMEL-10024: ---------------------------------------- No I don't know yet. But when doing a multithreaded test I recieve the wrong response in a thread when doing sync communication. Things that need to be checked: I guess a camel processor can be shared. I guess a mina session should not be shared but fetched inside the process method. Are my guesses correct? Op 13 jun. 2016 8:57 a.m. schreef "Niels Ull Harremoes (JIRA)" < > 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)