[
https://issues.apache.org/jira/browse/AMQ-6283?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16173144#comment-16173144
]
Maksym Dovgopolyi commented on AMQ-6283:
----------------------------------------
Dear Apache team,
We are using your product (apache-activemq-5.14.0) for the high loaded product
that provides messages (sms/viber) delivery service across 10+ countries and
for 50M + users.
Just yesterday we faced the described above issue what lead us to
unavailability of the service during 47 minutes and many unpleasant calls from
our clients.
Because of this, I would like you to clarify following moments:
The issue has a status OPEN since it created (more that one year) when to
expect the fix?
Will an update up to version 5.15.0 fix this problem or decrease a probability
of the risk to face this issue again?
Look forward to have your comments/answer soon.
Thank you!
> 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.4.14#64029)
