Peer topic clients losing connection, bug in Peer transport configuration?

[Oli <ol...@postea.com>]

I am using ActiveMQ 5.4.2

I have 2 clients (machines) that connect to a topic using the ActiveMQ Peer
Transport, Machine A and Machine B.
Both machines are running on Vista, both instances of the program (a
Netbeans built Java program) are run as jars in a command prompt.

My problem is this:
The machines connect to each other with no problems.
See log 1 below.
 
  
After a given period of time (the time period seems to be quite random, from
a couple of hours to well over 24 hours), the initial connection is stopped.
After the initial connection has been stopped (in this case to
MACHINE_A_IP:54012), Machine A never again receives any of the messages that
Machine B sends.
What seems to happen is that the connection is stopped and then Machine B
connects to Machine A using the same IP and a different port.
See log 2 below.

 
In addition, looking through the logs, I noticed an error that I have not
seen before (and I have tested this a few times) that directly precedes the
connection stopping above:
See log 3 below
 
	
So my question is this. Firstly, ss there a way of making sure that the
embedded broker peer transport connections are always made using the same
port, thereby preventing the reconnect error?
Or, secondly, is there a way of preventing the connection stop/start from
taking place at all?
Thirdly, is there a chance that a DHCP refresh (machines get reissued with
ip's) causes the break in the connection?

I am creating the peer connection in code, using the following lines:

            activeMQFactory = new ActiveMQConnectionFactory("peer://groupA/"
+ machineName + "?persistent=true&keepAlive=true");
            
            activeMQFactory.setConsumerFailoverRedeliveryWaitPeriod(30000);
            
            connection = activeMQFactory.createConnection(machineName,
machineName);

            connection.start();
            session = connection.createSession(false,
Session.AUTO_ACKNOWLEDGE);
			
This is causing me quite a bit of problems, because with the current level
of unpredictability in the behaviour of ActiveMQ, I can not see that it is
usable for my purposes.			
Hope someone can help, 

Oli

------------------- log 1 ------------

Milliseconds since program start: 2563 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 17:09:33,423 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.negociate(WireFormatNegotiator.java:125) 
 Message: tcp:///MACHINE_A_IP:54012 before negotiation:
OpenWireFormat{version=6, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false} 
 
Milliseconds since program start: 2566 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 17:09:33,426 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.negociate(WireFormatNegotiator.java:140) 
 Message: tcp:///MACHINE_A_IP:54012 after negotiation:
OpenWireFormat{version=6, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false} 
 
 
Milliseconds since program start: 2572 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 17:09:33,432 
 Location of log event:
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:673) 
 Message: Setting up new connection id: ID:CYKOR1-57201-1305302969206-5:1,
address: /MACHINE_A_IP:54012 

--------------------------------------


 ------------------ log 2 ------------
 
Milliseconds since program start: 6445336 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,309 
 Location of log event:
org.apache.activemq.broker.TransportConnection.doStop(TransportConnection.java:964) 
 Message: Stopping connection: /MACHINE_A_IP:54012 
 
Milliseconds since program start: 6445336 
 Classname of caller: org.apache.activemq.transport.tcp.TcpTransport 
 Date in ISO8601 format: 2011-05-13 18:56:53,309 
 Location of log event:
org.apache.activemq.transport.tcp.TcpTransport.doStop(TcpTransport.java:508) 
 Message: Stopping transport tcp:///MACHINE_A_IP:54012 
 
Milliseconds since program start: 6445352 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,325 
 Location of log event:
org.apache.activemq.broker.TransportConnection.doStop(TransportConnection.java:980) 
 Message: Stopped transport: /MACHINE_A_IP:54012 
 
Milliseconds since program start: 6445352 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,325 
 Location of log event:
org.apache.activemq.broker.TransportConnection.doStop(TransportConnection.java:1013) 
 Message: Cleaning up connection resources: /MACHINE_A_IP:54012 
 
Milliseconds since program start: 6445352 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,325 
 Location of log event:
org.apache.activemq.broker.TransportConnection.processRemoveConnection(TransportConnection.java:713) 
 Message: remove connection id: ID:Oli-54006-1305302972528-5:1 
 
Milliseconds since program start: 6445352 
 Classname of caller: org.apache.activemq.broker.region.AbstractRegion 
 Date in ISO8601 format: 2011-05-13 18:56:53,325 
 Location of log event:
org.apache.activemq.broker.region.AbstractRegion.removeConsumer(AbstractRegion.java:322) 
 Message: CYKOR1Machine removing consumer:
ID:Oli-54006-1305302972528-5:1:1:1 for destination:
ActiveMQ.Advisory.Consumer.>,topic://ActiveMQ.Advisory.TempQueue,topic://ActiveMQ.Advisory.TempTopic 
 
Milliseconds since program start: 6445352 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,325 
 Location of log event:
org.apache.activemq.broker.TransportConnection.doStop(TransportConnection.java:1023) 
 Message: Connection Stopped: /MACHINE_A_IP:54012 
 
Milliseconds since program start: 6446366 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 18:56:54,339 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.sendWireFormat(WireFormatNegotiator.java:82) 
 Message: Sending: WireFormatInfo { version=6, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} 
 
Milliseconds since program start: 6446381 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 18:56:54,354 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.negociate(WireFormatNegotiator.java:118) 
 Message: Received WireFormat: WireFormatInfo { version=6,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} 
 
Milliseconds since program start: 6446381 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 18:56:54,354 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.negociate(WireFormatNegotiator.java:125) 
 Message: tcp:///MACHINE_A_IP:54281 before negotiation:
OpenWireFormat{version=6, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false} 
 
Milliseconds since program start: 6446381 
 Classname of caller: org.apache.activemq.transport.WireFormatNegotiator 
 Date in ISO8601 format: 2011-05-13 18:56:54,354 
 Location of log event:
org.apache.activemq.transport.WireFormatNegotiator.negociate(WireFormatNegotiator.java:140) 
 Message: tcp:///MACHINE_A_IP:54281 after negotiation:
OpenWireFormat{version=6, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false} 
 
Milliseconds since program start: 6446413 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:54,386 
 Location of log event:
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:673) 
 Message: Setting up new connection id: ID:Oli-54006-1305302972528-6:1,
address: /MACHINE_A_IP:54281 
 
 --------------------------------------
 
 ------------------- log 3 ------------
 
 Milliseconds since program start: 6445336 
 Classname of caller: org.apache.activemq.broker.TransportConnection 
 Date in ISO8601 format: 2011-05-13 18:56:53,309 
 Location of log event:
org.apache.activemq.broker.TransportConnection.serviceTransportException(TransportConnection.java:236) 
 Message: Transport failed: java.io.EOFException 
 
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269)
	at
org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:227)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:219)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:202)
	at java.lang.Thread.run(Unknown Source)
	
-----------------------------------------


--
View this message in context: http://activemq.2283324.n4.nabble.com/Peer-topic-clients-losing-connection-bug-in-Peer-transport-configuration-tp3528791p3528791.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.