am trying to start the ActiveMQ 5.11 and I see a WARNING as below:
WARN | Transport Connection to: tcp://127.0.0.1:40890 failed: java.io.EOFException
My activemq.xml is as below:
keyStore="file:${JMS_KEY_STORE}"
keyStorePassword="${JMS_KEY_STORE_PASSWORD}"
trustStore="file:${JMS_TRUST_STORE}"
trustStorePassword="${JMS_TRUST_STORE_PASSWORD}"
/>
name="host1 and host2"
uri="static://(${JMS_X_SITE_CSV_URL})?wireFormat=ssl&wireFormat.maxInactivityDuration=30000"
dynamicOnly="true"
suppressDuplicateQueueSubscriptions = "true"
networkTTL="1"
/>
Here is the entire console log for this.
Java Runtime: Oracle Corporation 1.7.0_05 /usr/java/jdk1.7.0_05/jre
Heap sizes: current=1004928k free=994439k max=1004928k
JVM args: -Xmx1G -Dorg.apache.activemq.UseDedicatedTaskRunner=true -Djava.util.logging.config.file=logging.properties -Djava.security.auth.login.config=/home/dragon/activemq/conf/login.config -Dcom.sun.management.jmxremote -Djava.io.tmpdir=/home/dragon/activemq/tmp -Dactivemq.classpath=/home/dragon/activemq/conf; -Dactivemq.home=/home/dragon/activemq -Dactivemq.base=/home/dragon/activemq -Dactivemq.conf=/home/dragon/activemq/conf -Dactivemq.data=/home/dragon/activemq/data
Extensions classpath:
[/home/dragon/activemq/lib,/home/dragon/activemq/lib/camel,/home/dragon/activemq/lib/optional,/home/dragon/activemq/lib/web,/home/dragon/activemq/lib/extra]
ACTIVEMQ_HOME: /home/dragon/activemq
ACTIVEMQ_BASE: /home/dragon/activemq
ACTIVEMQ_CONF: /home/dragon/activemq/conf
ACTIVEMQ_DATA: /home/dragon/activemq/data
Loading message broker from: xbean:activemq.xml
INFO | Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@a842913: startup date [Fri Oct 07 08:14:02 IST 2016]; root of context hierarchy
INFO | PListStore:[/home/dragon/activemq/data/divinedragonbox/tmp_storage] started
INFO | Using Persistence Adapter: KahaDBPersistenceAdapter[/home/dragon/jms_store]
INFO | JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:15526/jmxrmi
INFO | KahaDB is version 5
INFO | Recovering from the journal ...
INFO | Recovery replayed 76 operations from the journal in 0.032 seconds.
INFO | Apache ActiveMQ 5.11.1 (divinedragonbox, ID:divinedragonbox-60914-1475824445361-0:1) is starting
INFO | Listening for connections at: tcp://divinedragonbox:15511
INFO | Connector openwire started
INFO | Listening for connections at: stomp://divinedragonbox:15512
INFO | Connector stomp started
INFO | Listening for connections at: ssl://divinedragonbox:15571
INFO | Connector ssl started
INFO | Establishing network connection from vm://divinedragonbox?async=false&network=true to ssl://localhost:15571
INFO | Connector vm://divinedragonbox started
INFO | Network Connector DiscoveryNetworkConnector:host1 and host2:BrokerService[divinedragonbox] started
INFO | Apache ActiveMQ 5.11.1 (divinedragonbox, ID:divinedragonbox-60914-1475824445361-0:1) started
INFO | For help or more information please see: http://activemq.apache.org
INFO | divinedragonbox Shutting down
INFO | Connector vm://divinedragonbox stopped
INFO | divinedragonbox bridge to Unknown stopped
WARN | Transport Connection to: tcp://127.0.0.1:40890 failed: java.io.EOFException
INFO | ActiveMQ WebConsole available at http://localhost:15521/
INFO | Initializing Spring FrameworkServlet 'dispatcher'
INFO | jolokia-agent: No access restrictor found at classpath:/jolokia-access.xml, access to all MBeans is allowed
I enabled the TRACE for the messages and I got the following snippets of exceptions in the log file.
2016-10-07 08:15:45,378 | TRACE | Execute[ActiveMQ ForwardingBridge StopTask] runnable: org.apache.activemq.network.DemandForwardingBridgeSupport$4@b3f451d | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,378 | TRACE | Created and running thread[ActiveMQ ForwardingBridge StopTask-5]: Thread[ActiveMQ ForwardingBridge StopTask-5,5,main] | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,379 | DEBUG | Caught exception sending shutdown | org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ ForwardingBridge StopTask-5
org.apache.activemq.transport.TransportDisposedIOException: Transport disposed.
at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:82)[activemq-broker-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.network.DemandForwardingBridgeSupport$4.run(DemandForwardingBridgeSupport.java:288)[activemq-broker-5.11.1.jar:5.11.1]
at java.lang.Thread.run(Thread.java:722)[:1.7.0_05]
2016-10-07 08:15:45,380 | DEBUG | Stopping transport ssl://localhost/127.0.0.1:15571 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,381 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,381 | TRACE | Execute[ActiveMQ Task] runnable: org.apache.activemq.transport.tcp.TcpTransport$1@a1848dc | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,381 | TRACE | Created and running thread[ActiveMQ Task-1]: Thread[ActiveMQ Task-1,5,main] | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,382 | TRACE | Closing socket 2a9a5d77[TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: Socket[addr=localhost/127.0.0.1,port=15571,localport=40999]] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1
2016-10-07 08:15:45,383 | DEBUG | Closed socket 2a9a5d77[TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: Socket[addr=localhost/127.0.0.1,port=15571,localport=40999]] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1
2016-10-07 08:15:45,384 | INFO | divinedragonbox bridge to Unknown stopped | org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,384 | TRACE | serviceLocalException: disposed true ex | org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ BrokerService[divinedragonbox] Task-4
org.apache.activemq.transport.TransportDisposedIOException: peer (vm://divinedragonbox#1) stopped.
at org.apache.activemq.transport.vm.VMTransport.stop(VMTransport.java:207)[activemq-broker-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.TransportFilter.stop(TransportFilter.java:65)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.TransportFilter.stop(TransportFilter.java:65)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.ResponseCorrelator.stop(ResponseCorrelator.java:132)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.broker.TransportConnection.doStop(TransportConnection.java:1151)[activemq-broker-5.11.1.jar:5.11.1]
at org.apache.activemq.broker.TransportConnection$4.run(TransportConnection.java:1117)[activemq-broker-5.11.1.jar:5.11.1]
at java.lang.Thread.run(Thread.java:722)[:1.7.0_05]
2016-10-07 08:15:45,384 | DEBUG | Stopped transport: vm://divinedragonbox#0 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,384 | TRACE | Shutdown timeout: 1 task: Transport Connection to: vm://divinedragonbox#0 | org.apache.activemq.thread.DedicatedTaskRunner | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,385 | TRACE | Run task done: Transport Connection to: vm://divinedragonbox#0 | org.apache.activemq.thread.DedicatedTaskRunner | ActiveMQ Connection Dispatcher: vm://divinedragonbox#0
2016-10-07 08:15:45,385 | DEBUG | Connection Stopped: vm://divinedragonbox#0 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[divinedragonbox] Task-4
2016-10-07 08:15:45,385 | TRACE | Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@dfe196a[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0] with await termination: 0 millis | org.apache.activemq.util.ThreadPoolUtils | ActiveMQ Transport: ssl:///127.0.0.1:40999
2016-10-07 08:15:45,385 | DEBUG | Shutting down VM connectors for broker: divinedragonbox | org.apache.activemq.transport.vm.VMTransportFactory | triggerStartAsyncNetworkBridgeCreation: remoteBroker=ssl://localhost/127.0.0.1:15571, localBroker= vm://divinedragonbox#0
2016-10-07 08:15:45,385 | INFO | Connector vm://divinedragonbox stopped | org.apache.activemq.broker.TransportConnector | triggerStartAsyncNetworkBridgeCreation: remoteBroker=ssl://localhost/127.0.0.1:15571, localBroker= vm://divinedragonbox#0
2016-10-07 08:15:45,400 | DEBUG | Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@dfe196a[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0] is shutdown: true and terminated: true took: 0.001 seconds. | org.apache.activemq.util.ThreadPoolUtils | ActiveMQ Transport: ssl:///127.0.0.1:40999
2016-10-07 08:15:45,400 | DEBUG | Transport Connection to: tcp://127.0.0.1:40999 failed: java.io.EOFException | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ Transport: ssl:///127.0.0.1:40999
java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:392)[:1.7.0_05]
at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:258)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:221)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:213)[activemq-client-5.11.1.jar:5.11.1]
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)[activemq-client-5.11.1.jar:5.11.1]
at java.lang.Thread.run(Thread.java:722)[:1.7.0_05]
2016-10-07 08:15:45,401 | DEBUG | Unregistering MBean org.apache.activemq:type=Broker,brokerName=divinedragonbox,connector=clientConnectors,connectorName=ssl,connectionViewType=remoteAddress,connectionName=tcp_//127.0.0.1_40999 | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport: ssl:///127.0.0.1:40999
2016-10-07 08:15:45,401 | TRACE | Execute[ActiveMQ BrokerService[divinedragonbox] Task] runnable: org.apache.activemq.broker.TransportConnection$4@5039f4d3 | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ Transport: ssl:///127.0.0.1:40999
2016-10-07 08:15:45,401 | TRACE | Created and running thread[ActiveMQ BrokerService[divinedragonbox] Task-6]: Thread[ActiveMQ BrokerService[divinedragonbox] Task-6,8,main] | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ Transport: ssl:///127.0.0.1:40999
Can somebody tell me why are these exceptions thrown?
I can provide the entire log file if anybody needs for a deeper look.
解决方案
So, I finally got to the root cause of this. This WARNING comes because the way networkConnector works and configured. I had posted this on the activemq community here - http://activemq.2283324.n4.nabble.com/java-io-EOFException-when-ActiveMQ-starts-td4717598.html
When networkConnector is used, activemq tries to connect to the broker configured. In my case, I was trying to self-connect to the broker and that is why it was rejecting the connection. The same was pointed by Tim in the community.
I've never tried configuring a broker with a static networkConnector
connected to itself (why would I, it's a useless configuration), but
it wouldn't surprise me if the broker rejected that self-connection,
which could result in the EOFException you saw. It's also possible
that there's something wrong with your SSL configuration as you
suggested; there's no good way in a mailing list discussion to check
whether your truststore trusts your keystore and the certs are being
presented properly since that's all about the binary content and you
shouldn't be sharing that publicly, but you could test the SSL
configuration by setting up two brokers (in a test environment) that
each have their JMS_X_SITE_CSV_URL pointed at each other. If that
configuration gives you EOFExceptions, then switch to using the tcp
transport and see what happens. If you get errors with the ssl
transport but not the tcp one, there's a good chance it's something
wrong with your keys.
As far as the current configuration (where you have a broker whose
only networkConnection is a static:ssl: one to itself), it's not a
useful configuration (having a networkConnector to yourself serves no
purpose), and you proved early on in this discussion that removing it
removes the WARN log line that you're concerned about. So I disagree
with your statement that "I feel the configuration still seems fine."
Either switch to something that serves the purpose you said you're
trying to achieve (like the discovery: transport instead of the
static: transport, or like listing your cross-site servers if you're
going to continue using the static: transport) or take it out and
eliminate the WARN line.
So, networkConnector is essentially of no use if it is a single broker system. Makes more sense in multi-broker deployments and then all the brokers are configured, except the self on each broker separately.
To still make the networkConnector configuration to work in single broker deployment, the value I had to set was - url="static://(ssl://divinedragonbox:7031)..."(Hostname instead of IP Address or localhost). That gets rid of the WARNING which comes.