activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From D Howe <david.h...@sensis.com.au>
Subject Network of brokers losing messages in 3.2.2
Date Mon, 27 Mar 2006 06:31:50 GMT

I'm trying to setup a network of brokers, as per the documentation, to
provide a level of redundancy.  The configuration that I have is one
instance of an application that is producing messages on a queue, a network
of two ActiveMQ brokers running on the same machine and one instance of an
application that is consuming the messages from the queue.

The relevant bits of my broker configuration files are:

Broker 1

    <connector>
      <tcpServerTransport uri="tcp://localhost:61617" backlog="1000"
useAsyncSend="true" maxOutstandingMessages="50"/>
    </connector>

    <networkConnector>
      <networkChannel uri="reliable:tcp://localhost:61618"
remoteBrokerName="cluster1" remoteUserName="pfp" remotePassword="password"
/>
    </networkConnector>

Broker 2

    <connector>
      <tcpServerTransport uri="tcp://localhost:61618" backlog="1000"
useAsyncSend="true" maxOutstandingMessages="50"/>
    </connector>

    <networkConnector>
      <networkChannel uri="reliable:tcp://localhost:61617"
remoteBrokerName="cluster2" remoteUserName="pfp" remotePassword="password"/>
    </networkConnector>

And my producer and consumer are using the URL:

reliable:tcp://localhost:61617,tcp://localhost:61618

The test that I am running on the producing application produces 100
messages onto the queue.  The consuming application then consumes these
messages and updates records in its own database.

When I have only one broker running in the network of ActiveMQ brokers,
everything works fine - 100 messages produced and 100 messages consumed. I
have run this test many times with no problems.

When I bring up the second broker, the two brokers see each other as shown
in the console output:

BROKER 1 startup log

ActiveMQ Message Broker (http://activemq.org/)

Loading Mesaage Broker from activemq.xml on the CLASSPATH
15:44:47 INFO  JDK 1.4+ collections available
15:44:47 INFO  ActiveMQ 3.2.2 JMS Message Broker (cluster1) is starting
15:44:47 INFO  For help or more information please see:
http://www.logicblaze.co
m
15:44:49 INFO  Database driver recognized:
[apache_derby_embedded_jdbc_driver]
15:44:50 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250),
MSGI
D VARCHAR(250), MSG BLOB, PRIMARY KEY ( ID ) ) Message: Table/View
'ACTIVEMQ_MSG
S' already exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 20000
15:44:50 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_TXS(XID VARCHAR(250) NOT NULL, PRIMARY KEY ( XID
)) Me
ssage: Table/View 'ACTIVEMQ_TXS' already exists in Schema 'APP'. SQLState:
X0Y32
 Vendor code: 20000
15:44:50 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_ACKS(SUB VARCHAR(250) NOT NULL, CONTAINER
VARCHAR(250)
 NOT NULL, LAST_ACKED_ID INTEGER, SE_ID INTEGER, SE_CLIENT_ID VARCHAR(250),
SE_C
ONSUMER_NAME VARCHAR(250), SE_SELECTOR VARCHAR(250), PRIMARY KEY ( SUB,
CONTAINE
R )) Message: Table/View 'ACTIVEMQ_ACKS' already exists in Schema 'APP'.
SQLStat
e: X0Y32 Vendor code: 20000
15:44:50 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: ALTER TABLE ACTIVEMQ_MSGS ADD EXPIRATION BIGINT Message: Column
'EXPIRATION'
 already exists in Table/View 'APP.ACTIVEMQ_MSGS'. SQLState: X0Y32 Vendor
code:
20000
15:44:50 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: ALTER TABLE ACTIVEMQ_MSGS ADD SENT_TO_DEADLETTER CHAR(1) Message: Column
'SE
NT_TO_DEADLETTER' already exists in Table/View 'APP.ACTIVEMQ_MSGS'.
SQLState: X0
Y32 Vendor code: 20000
15:44:50 INFO  Opening journal.
15:44:51 INFO  Opened journal: Active Journal: using 5 x 40.0 Megs at:
..\var\jo
urnal
15:44:51 INFO  Journal Recovery Started.
15:44:51 INFO  Journal Recovered: 1 message(s) in transactions recovered.
15:44:51 INFO  Listening for connections at: tcp://L102930:61617
15:44:51 INFO  ActiveMQ connector started:
TcpTransportServerChannel@tcp://L1029
30:61617
15:44:51 INFO  ActiveMQ JMS Message Broker (cluster1) has started
15:44:51 INFO  Listening for connections at: vm://cluster1
15:44:51 INFO  ActiveMQ connector started:
VmTransportServerChannel@vm://cluster
1
15:44:51 INFO  Embedded JMS Broker has started
15:44:51 INFO  Adding new client: cluster2_NetworkChannel on transport:
TcpTrans
portChannel: Socket[addr=/127.0.0.1,port=4465,localport=61617]
15:44:52 INFO  Adding new client: ID:L102930-4462-1143438287192-6:0 on
transport
: VmTransportChannel: null
15:44:52 INFO  channel status changed: Channel: ReliableTransportChannel:
TcpTra
nsportChannel: Socket[addr=localhost/127.0.0.1,port=61618,localport=4467]
has co
nnected
15:44:52 INFO  started NetworkMessageBridge for destination: core.track --
Netwo
rkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61618' ,
remoteBrok
erName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination: publish.request
--
NetworkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61618' ,
remot
eBrokerName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination:
core.internal.bulkU
pload -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost:61618
' , remoteBrokerName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination: core.publish --
Net
workChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61618' ,
remoteBr
okerName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination:
core.internal.publi
cation -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost:6161
8' , remoteBrokerName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination:
ActiveMQ.Advisory.C
onnections. -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost
:61618' , remoteBrokerName = 'cluster2'  }
15:44:52 INFO  started NetworkMessageBridge for destination:
billing.response --
 NetworkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61618' ,
remo
teBrokerName = 'cluster2'  }
15:44:52 INFO  Started NetworkChannel to reliable:tcp://localhost:61618
15:45:19 INFO  Adding new client: ID:L102930-4391-1143437954183-1:0 on
transport
: TcpTransportChannel: Socket[addr=/127.0.0.1,port=4475,localport=61617]
15:45:20 WARN  Peer closed connection
java.io.EOFException
        at java.io.DataInputStream.readByte(DataInputStream.java:333)
        at
org.activemq.io.AbstractWireFormat.readPacket(AbstractWireFormat.java
:230)
        at
org.activemq.transport.tcp.TcpTransportChannel.run(TcpTransportChanne
l.java:313)
        at java.lang.Thread.run(Thread.java:534)
15:45:20 INFO  channel status changed: Channel: ReliableTransportChannel:
TcpTra
nsportChannel: Socket[addr=localhost/127.0.0.1,port=61618,localport=4467]
has di
sconnected
15:45:20 INFO  Removing client: cluster2_NetworkChannel on transport:
TcpTranspo
rtChannel: Socket[addr=/127.0.0.1,port=4465,localport=61617]
15:45:20 INFO  channel status changed: Channel: tcp://localhost:61618 has
discon
nected
15:45:20 INFO  stopped MetworkMessageBridge for destination:
ActiveMQ.Advisory.C
onnections.
15:45:21 INFO  Could not connect to: tcp://localhost:61618. Reason:
javax.jms.JM
SException: Initialization of TcpTransportChannel failed. URI was:
tcp://localho
st:61618 Reason: java.net.ConnectException: Connection refused: connect
15:45:21 INFO  Could not connect; sleeping for: 2000 millis and trying again
15:45:24 INFO  Could not connect to: tcp://localhost:61618. Reason:
javax.jms.JM
SException: Initialization of TcpTransportChannel failed. URI was:
tcp://localho
st:61618 Reason: java.net.ConnectException: Connection refused: connect
15:45:24 INFO  Could not connect; sleeping for: 2000 millis and trying again
15:45:27 INFO  Could not connect to: tcp://localhost:61618. Reason:
javax.jms.JM
SException: Initialization of TcpTransportChannel failed. URI was:
tcp://localho
st:61618 Reason: java.net.ConnectException: Connection refused: connect
15:45:27 INFO  Could not connect; sleeping for: 2000 millis and trying again
15:45:30 INFO  Could not connect to: tcp://localhost:61618. Reason:
javax.jms.JM
SException: Initialization of TcpTransportChannel failed. URI was:
tcp://localho
st:61618 Reason: java.net.ConnectException: Connection refused: connect
15:45:30 INFO  Could not connect; sleeping for: 2000 millis and trying again
15:45:32 INFO  channel status changed: Channel: tcp://localhost:61618 has
reconn
ected
15:45:35 INFO  Adding new client: cluster2_NetworkChannel on transport:
TcpTrans
portChannel: Socket[addr=/127.0.0.1,port=4482,localport=61617]
15:45:49 INFO  Adding new client: ID:L102930-3770-1143418540498-1:0 on
transport
: TcpTransportChannel: Socket[addr=/127.0.0.1,port=4483,localport=61617]

BROKER 2 Startup log
ActiveMQ Message Broker (http://activemq.org/)

Loading Mesaage Broker from activemq.xml on the CLASSPATH
15:45:31 INFO  JDK 1.4+ collections available
15:45:31 INFO  ActiveMQ 3.2.2 JMS Message Broker (cluster2) is starting
15:45:31 INFO  For help or more information please see:
http://www.logicblaze.co
m
15:45:32 INFO  Database driver recognized:
[apache_derby_embedded_jdbc_driver]
15:45:33 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250),
MSGI
D VARCHAR(250), MSG BLOB, PRIMARY KEY ( ID ) ) Message: Table/View
'ACTIVEMQ_MSG
S' already exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 20000
15:45:33 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_TXS(XID VARCHAR(250) NOT NULL, PRIMARY KEY ( XID
)) Me
ssage: Table/View 'ACTIVEMQ_TXS' already exists in Schema 'APP'. SQLState:
X0Y32
 Vendor code: 20000
15:45:33 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: CREATE TABLE ACTIVEMQ_ACKS(SUB VARCHAR(250) NOT NULL, CONTAINER
VARCHAR(250)
 NOT NULL, LAST_ACKED_ID INTEGER, SE_ID INTEGER, SE_CLIENT_ID VARCHAR(250),
SE_C
ONSUMER_NAME VARCHAR(250), SE_SELECTOR VARCHAR(250), PRIMARY KEY ( SUB,
CONTAINE
R )) Message: Table/View 'ACTIVEMQ_ACKS' already exists in Schema 'APP'.
SQLStat
e: X0Y32 Vendor code: 20000
15:45:34 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: ALTER TABLE ACTIVEMQ_MSGS ADD EXPIRATION BIGINT Message: Column
'EXPIRATION'
 already exists in Table/View 'APP.ACTIVEMQ_MSGS'. SQLState: X0Y32 Vendor
code:
20000
15:45:34 INFO  Could not create JDBC tables; they could already exist.
Failure w
as: ALTER TABLE ACTIVEMQ_MSGS ADD SENT_TO_DEADLETTER CHAR(1) Message: Column
'SE
NT_TO_DEADLETTER' already exists in Table/View 'APP.ACTIVEMQ_MSGS'.
SQLState: X0
Y32 Vendor code: 20000
15:45:34 INFO  Opening journal.
15:45:34 INFO  Opened journal: Active Journal: using 5 x 40.0 Megs at:
..\var\jo
urnal
15:45:34 INFO  Journal Recovery Started.
15:45:34 INFO  Journal Recovered: 1 message(s) in transactions recovered.
15:45:34 INFO  Listening for connections at: tcp://L102930:61618
15:45:34 INFO  ActiveMQ connector started:
TcpTransportServerChannel@tcp://L1029
30:61618
15:45:34 INFO  ActiveMQ JMS Message Broker (cluster2) has started
15:45:34 INFO  Listening for connections at: vm://cluster2
15:45:34 INFO  ActiveMQ connector started:
VmTransportServerChannel@vm://cluster
2
15:45:34 INFO  Embedded JMS Broker has started
15:45:34 INFO  Adding new client: cluster1_NetworkChannel on transport:
TcpTrans
portChannel: Socket[addr=/127.0.0.1,port=4481,localport=61618]
15:45:35 INFO  Adding new client: ID:L102930-4480-1143438330815-6:0 on
transport
: VmTransportChannel: null
15:45:35 INFO  channel status changed: Channel: ReliableTransportChannel:
TcpTra
nsportChannel: Socket[addr=localhost/127.0.0.1,port=61617,localport=4482]
has co
nnected
15:45:35 INFO  started NetworkMessageBridge for destination: core.publish --
Net
workChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61617' ,
remoteBr
okerName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination:
core.internal.bulkU
pload -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost:61617
' , remoteBrokerName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination: publish.request
--
NetworkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61617' ,
remot
eBrokerName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination: core.track --
Netwo
rkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61617' ,
remoteBrok
erName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination:
ActiveMQ.Advisory.C
onnections. -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost
:61617' , remoteBrokerName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination:
billing.response --
 NetworkChannel: NetworkChannel{ , uri = 'reliable:tcp://localhost:61617' ,
remo
teBrokerName = 'cluster1'  }
15:45:35 INFO  started NetworkMessageBridge for destination:
core.internal.publi
cation -- NetworkChannel: NetworkChannel{ , uri =
'reliable:tcp://localhost:6161
7' , remoteBrokerName = 'cluster1'  }
15:45:35 INFO  Started NetworkChannel to reliable:tcp://localhost:61617

I think now that I should have two brokers that can see each other, and with
the demand based forwarding added in 3.2 messages should be passed between
them to whoever has a consumer for the queue that the message was placed on.

The behaviour that I am seeing is that sometimes this works.  Sometimes,
there will be one or two messages short of the number that I expect. 
Occasionally, there will be a larger number of messages missing (20 - 25 out
of 100).

When I notice that there are messages missing, if I stop and start the
ActiveMQ brokers in turn, quite often all of the messages come back and are
processed.  Sometimes, however, the messages are just gone without a trace. 
I have tried browsing the queue on both brokers using Hermes and the
messages aren't there.  I've also tried restarting the consuming application
multiple times to make it connect to both brokers, and the messages aren't
there to be consumed.  You have to restart the broker for the messages to
appear.

My questions are:

1) With the setup I have described above, is there any reason why all of the
messages wouldn't reach the consumer when running a network of brokers
2) Is the above behaviour expected/explainable
3) Is there any way in 3.2.2 to use a network of brokers to get some
redundancy.  All I am trying to achieve is for:
  a) ActiveMQ not to be a single point of failure
  b) Messages not to be orphaned on a broker in the cluster that currently
doesn't have any consumers on that queue.  It looks like the
demandBasedForwarding property (default=true) was added to the
NetworkChannel class in 3.2 to cover this situation

I'm aware that a lot of work has been done on clustering in release 4, but
I'm currently not in a good position to go to version 4 as we are near the
end of a test cycle using release 3, and re-testing would incur significant
effort and delay. Version 4 not being final also complicates things.

Any help or suggestions greatly appreciated.
--
View this message in context: http://www.nabble.com/Network-of-brokers-losing-messages-in-3.2.2-t1347397.html#a3604559
Sent from the ActiveMQ - User forum at Nabble.com.


Mime
View raw message