infinite loop when connecting to a stopped acceptor
jmesnil Dec 11, 2008 12:15 PMI'm currently adding management operations to start/stop JBM2 acceptors.
One of my tests ends up with a infinite loop when connecting to an acceptor that I've just stopped (I was expecting to have an error when creating the connection instead).
My code is in a middle of a refactoring but I'm able to reproduce it using the trunk code:
public void testStartStop2() throws Exception { TransportConfiguration acceptorConfig = new TransportConfiguration(NettyAcceptorFactory.class.getName(), new HashMap<String, Object>(), randomString()); Configuration conf = new ConfigurationImpl(); conf.setSecurityEnabled(false); conf.setJMXManagementEnabled(false); conf.getAcceptorConfigurations().add(acceptorConfig); MessagingService service = MessagingServiceImpl.newNullStorageMessagingService(conf); service.start(); Connection connection = JMSUtil.createConnection(NettyConnectorFactory.class.getName()); assertNotNull(connection); // create a session to check the connection is working properly connection.createSession(false, Session.AUTO_ACKNOWLEDGE); connection.close(); // this simulates the management method to stop an acceptor Set<Acceptor> acceptors = service.getServer().getRemotingService().getAcceptors(); assertEquals(1, acceptors.size()); Acceptor acceptor = acceptors.iterator().next(); assertNotNull(acceptor); acceptor.stop(); try { connection = JMSUtil.createConnection(NettyConnectorFactory.class.getName()); assertNotNull(connection); connection.createSession(false, Session.AUTO_ACKNOWLEDGE); fail("acceptor must not accept connections when stopped"); } catch (Exception e) { } /* acceptor.start(); connection = JMSUtil.createConnection(NettyConnectorFactory.class.getName()); assertNotNull(connection); connection.createSession(false, Session.AUTO_ACKNOWLEDGE); // create a session to check the connection is working properly connection.close(); */ }
the test is simple:
- start JBM2 with a single netty acceptor
- create a connection and check it works
- stop the (only) acceptor
- create a connection <- expected failure
- start the acceptor
- create a connection and check it works
the test also gives an infinite loop if I stop the whole messaging service (instead of stopping only the acceptor)
The logs show that I've a infinite loop when I create the connection after stopping the acceptor:
11 déc. 2008 18:13:17 org.jboss.messaging.core.logging.Logger info INFO: Started messaging server 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Commencing automatic failover / reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Attempting reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Successfully reconnected 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger error GRAVE: caught exception java.net.ConnectException: Connection refused for channel NioClientSocketChannel(id: 2709c0a8-011e-1000-8cab-013f31dc9386) java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:527) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.connect(NioClientSocketPipelineSink.java:300) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.processSelectedKeys(NioClientSocketPipelineSink.java:292) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.run(NioClientSocketPipelineSink.java:231) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:613) 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger error GRAVE: caught exception java.net.ConnectException: Connection refused for channel NioClientSocketChannel(id: 2709c0a8-011e-1000-8cac-013f31dc9386) java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:527) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.connect(NioClientSocketPipelineSink.java:300) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.processSelectedKeys(NioClientSocketPipelineSink.java:292) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.run(NioClientSocketPipelineSink.java:231) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:613) 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Commencing automatic failover / reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Attempting reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Successfully reconnected 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger error GRAVE: caught exception java.net.ConnectException: Connection refused for channel NioClientSocketChannel(id: 2709c0a8-011e-1000-8cad-013f31dc9386) java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:527) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.connect(NioClientSocketPipelineSink.java:300) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.processSelectedKeys(NioClientSocketPipelineSink.java:292) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.run(NioClientSocketPipelineSink.java:231) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:613) 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Commencing automatic failover / reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Attempting reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Successfully reconnected 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Commencing automatic failover / reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Attempting reconnection 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Successfully reconnected 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger error GRAVE: caught exception java.net.ConnectException: Connection refused for channel NioClientSocketChannel(id: 2709c0a8-011e-1000-8cae-013f31dc9386) java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:527) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.connect(NioClientSocketPipelineSink.java:300) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.processSelectedKeys(NioClientSocketPipelineSink.java:292) at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink$Boss.run(NioClientSocketPipelineSink.java:231) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:613) 11 déc. 2008 18:13:18 org.jboss.messaging.core.logging.Logger info INFO: Commencing automatic failover / reconnection
and it continues like that on and on.
The repeated "Successfully reconnected" log are weird: there seems to be a code path that we're missing