You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Johan Carlquist (JIRA)" <ji...@apache.org> on 2016/05/09 07:48:12 UTC
[jira] [Created] (AMQ-6283) NC of network of brokers won't
reconnect after broken pipe
Johan Carlquist created AMQ-6283:
------------------------------------
Summary: NC of network of brokers won't reconnect after broken pipe
Key: AMQ-6283
URL: https://issues.apache.org/jira/browse/AMQ-6283
Project: ActiveMQ
Issue Type: Bug
Components: Broker, networkbridge
Affects Versions: 5.13.0
Environment: # lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04.4 LTS
Release: 14.04
Codename: trusty
# /local/jdk/bin/java -version
java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)
Reporter: Johan Carlquist
After mq01 got disconnected due to broken pipe it refused to reconnect because mq02 thinks it already has an outbound connection with mq01.
Mq01 logs:
{code}
May 6 12:41:31 localhost {"timeMillis": 1462531291674,"thread":"ActiveMQ Transport: ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq01.it.su.se#10 and ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616 shutdown due to a
local error: org.apache.activemq.transport.TransportDisposedIOException: Disposed due to prior exception","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291675,"thread":"ActiveMQ Transport: ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq01.it.su.se#10 and ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616 shutdown due to a
local error: org.apache.activemq.transport.TransportDisposedIOException: Disposed due to prior exception","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": message repeated 3 times: [1462531291675,"thread":"ActiveMQ Transport: ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq01.it.su.se#10 and ssl://esb-prod-mq02.it.su.se/77.238.36.1
00:61616 shutdown due to a local error: org.apache.activemq.transport.TransportDisposedIOException: Disposed due to prior exception","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}]
May 6 12:41:31 localhost {"timeMillis": 1462531291674,"thread":"ActiveMQ BrokerService[esb-prod-mq01.it.su.se] Task-5014","level":"WARN","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Caught an exception processing local command","thrown":{"commonElementCount":0,"localizedMessage":"Broken pipe","message":"Broken pipe","name
":"java.net.SocketException","extendedStackTrace":[{"class":"java.net.SocketOutputStream","method":"socketWrite0","file":"SocketOutputStream.java","line":-2,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"java.net.SocketOutputStream","method":"socketWrite","file":"SocketOutputStream.java","line":109,"exact":false,"location":"?","version":"1.8.0_45"
},{"class":"java.net.SocketOutputStream","method":"write","file":"SocketOutputStream.java","line":153,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"sun.security.ssl.OutputRecord","method":"writeBuffer","file":"OutputRecord.java","line":431,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"sun.security.ssl.OutputRecord","method":"write"
,"file":"OutputRecord.java","line":417,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"sun.security.ssl.SSLSocketImpl","method":"writeRecordInternal","file":"SSLSocketImpl.java","line":864,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"sun.security.ssl.SSLSocketImpl","method":"writeRecord","file":"SSLSocketImpl.java","line":835,"exact
":false,"location":"?","version":"1.8.0_45"},{"class":"sun.security.ssl.AppOutputStream","method":"write","file":"AppOutputStream.java","line":123,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"org.apache.activemq.transport.tcp.TcpBufferedOutputStream","method":"flush","file":"TcpBufferedOutputStream.java","line":115,"exact":false,"location":"acti
vemq-client-5.13.0.jar","version":"5.13.0"},{"class":"java.io.DataOutputStream","method":"flush","file":"DataOutputStream.java","line":123,"exact":false,"location":"?","version":"1.8.0_45"},{"class":"org.apache.activemq.transport.tcp.TcpTransport","method":"oneway","file":"TcpTransport.java","line":194,"exact":false,"location":"activemq-client-5.13.0.jar","vers
ion":"5.13.0"},{"class":"org.apache.activemq.transport.AbstractInactivityMonitor","method":"doOnewaySend","file":"AbstractInactivityMonitor.java","line":334,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.AbstractInactivityMonitor","method":"oneway","file":"AbstractInactivityMonitor.java","line":
316,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.TransportFilter","method":"oneway","file":"TransportFilter.java","line":85,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.WireFormatNegotiator","method":"oneway","file":"WireForm
atNegotiator.java","line":116,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.MutexTransport","method":"oneway","file":"MutexTransport.java","line":68,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.ResponseCorrelator","method":"as
yncRequest","file":"ResponseCorrelator.java","line":81,"exact":false,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.network.DemandForwardingBridgeSupport","method":"serviceLocalCommand","file":"DemandForwardingBridgeSupport.java","line":1009,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"cla
ss":"org.apache.activemq.network.DemandForwardingBridgeSupport$2","method":"onCommand","file":"DemandForwardingBridgeSupport.java","line":207,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.ResponseCorrelator","method":"onCommand","file":"ResponseCorrelator.java","line":116,"exact":true,"location"
:"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.MutexTransport","method":"onCommand","file":"MutexTransport.java","line":50,"exact":true,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.vm.VMTransport","method":"doDispatch","file":"VMTransport.java","line":162,"exact":t
rue,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.vm.VMTransport","method":"dispatch","file":"VMTransport.java","line":154,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.vm.VMTransport","method":"oneway","file":"VMTransport.java","line":131,"e
xact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.MutexTransport","method":"oneway","file":"MutexTransport.java","line":68,"exact":true,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.transport.ResponseCorrelator","method":"oneway","file":"ResponseCorrelator.j
ava","line":60,"exact":true,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.broker.TransportConnection","method":"dispatch","file":"TransportConnection.java","line":1433,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.broker.TransportConnection","method":"processDis
patch","file":"TransportConnection.java","line":947,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.broker.TransportConnection","method":"iterate","file":"TransportConnection.java","line":993,"exact":true,"location":"activemq-broker-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.thread.Pooled
TaskRunner","method":"runTask","file":"PooledTaskRunner.java","line":133,"exact":true,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"org.apache.activemq.thread.PooledTaskRunner$1","method":"run","file":"PooledTaskRunner.java","line":48,"exact":true,"location":"activemq-client-5.13.0.jar","version":"5.13.0"},{"class":"java.util.concurrent.
ThreadPoolExecutor","method":"runWorker","file":"ThreadPoolExecutor.java","line":1142,"exact":true,"location":"?","version":"1.8.0_45"},{"class":"java.util.concurrent.ThreadPoolExecutor$Worker","method":"run","file":"ThreadPoolExecutor.java","line":617,"exact":true,"location":"?","version":"1.8.0_45"},{"class":"java.lang.Thread","method":"run","file":"Thread.ja
va","line":745,"exact":true,"location":"?","version":"1.8.0_45"}]},"endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291676,"thread":"ActiveMQ Task-4","level":"INFO","loggerName":"org.apache.activemq.network.DiscoveryNetworkConnector","message":"Establishing network connection from vm://esb-prod-mq01.it.su.se?async=false to ssl://esb-prod-mq02.it.su.se:61616","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291729,"thread":"ActiveMQ BrokerService[esb-prod-mq01.it.su.se] Task-5125","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"esb-prod-mq01.it.su.se bridge to esb-prod-mq02.it.su.se stopped","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291819,"thread":"triggerStartAsyncNetworkBridgeCreation: remoteBroker=ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616, localBroker= vm://esb-prod-mq01.it.su.se#12","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq01.it.su
.se#12 and ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616 (esb-prod-mq02.it.su.se) has been established.","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291849,"thread":"ActiveMQ Transport: ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616","level":"WARN","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq01.it.su.se#12 and ssl://esb-prod-mq02.it.su.se/77.238.36.100:61616 shutdown due to a
remote error: javax.jms.InvalidClientIDException: Broker: esb-prod-mq02.it.su.se - Client: NC_esb-prod-mq01.it.su.se_outbound already connected from tcp://77.238.36.99:33618","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291860,"thread":"ActiveMQ BrokerService[esb-prod-mq01.it.su.se] Task-5125","level":"INFO","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"esb-prod-mq01.it.su.se bridge to esb-prod-mq02.it.su.se stopped","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:32 localhost {"timeMillis": 1462531292849,"thread":"ActiveMQ Task-4","level":"INFO","loggerName":"org.apache.activemq.network.DiscoveryNetworkConnector","message":"Establishing network connection from vm://esb-prod-mq01.it.su.se?async=false to ssl://esb-prod-mq02.it.su.se:61616","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
{code}
mq02 logs:
{code}
May 6 12:41:31 localhost {"timeMillis": 1462531291836,"thread":"ActiveMQ NIO Worker 7878","level":"WARN","loggerName":"org.apache.activemq.broker.TransportConnection","message":"Failed to add Connection esb-prod-mq01.it.su.se->esb-prod-mq02.it.su.se-54927-1461934227469-14:2 due to javax.jms.InvalidClientIDException: Broker: esb-prod-mq02.it.su.se - Client: NC_esb-prod-mq01.it.su.se_outbound already connected from tcp://77.238.36.99:33618","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291836,"thread":"ActiveMQ NIO Worker 7878","level":"WARN","loggerName":"org.apache.activemq.broker.TransportConnection.Service","message":"Async error occurred: javax.jms.InvalidClientIDException: Broker: esb-prod-mq02.it.su.se - Client: NC_esb-prod-mq01.it.su.se_outbound already connected from tcp://77.238.36.99:33618","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291840,"thread":"ActiveMQ NIO Worker 7878","level":"WARN","loggerName":"org.apache.activemq.broker.TransportConnection.Service","message":"Async error occurred: java.lang.IllegalStateException: Cannot add a producer to a connection that had not been registered: esb-prod-mq01.it.su.se->esb-prod-mq02.it.su.se-54927-1461934227469-14:2","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 12:41:31 localhost {"timeMillis": 1462531291840,"thread":"ActiveMQ NIO Worker 7878","level":"WARN","loggerName":"org.apache.activemq.broker.TransportConnection.Service","message":"Async error occurred: java.lang.IllegalStateException: Cannot add a consumer to a connection that had not been registered: esb-prod-mq01.it.su.se->esb-prod-mq02.it.su.se-54927-1461934227469-14:2","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
May 6 15:27:20 localhost {"timeMillis": 1462541240779,"thread":"ActiveMQ Transport: ssl://esb-prod-mq01.it.su.se/77.238.36.99:61616","level":"WARN","loggerName":"org.apache.activemq.network.DemandForwardingBridgeSupport","message":"Network connection between vm://esb-prod-mq02.it.su.se#0 and ssl://esb-prod-mq01.it.su.se/77.238.36.99:61616 shutdown due to a remote error: java.io.EOFException","endOfBatch":false,"loggerFqcn":"org.slf4j.impl.Log4jLoggerAdapter"}
{code}
Last log line appeared after rebooting mq01.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)