You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by tomek <to...@seamless.se> on 2013/08/22 11:47:42 UTC
No message delivery vs ACTIVEMQ_MSGS
Hi,
I'm working on ActiveMQ 5.8.0 with MySQL as a data source. The configuration
of ActiveMQ is attached (activemq.xml). It is used in a basic scenario: a
producer sends a short message (JSON object with 2 fields) with 5s delay to
queue T on which 3 consumers listen. The consumers are created using plain
Java API:
for (int i = 0; i < numberOfConsumer; i++)
{
Session session = connection.createSession(false,
Session.AUTO_ACKNOWLEDGE);
Destination destination = session.createQueue(queueName);
MessageConsumer consumer = session.createConsumer(destination);
MyConsumer myConsumer = new MyConsumer();
consumer.setMessageListener(myConsumer);
connection.setExceptionListener(myConsumer);
consumers.add(invoiceConsumer);
}
MyConsumer class implements both javax.jms.ExceptionListener and
javax.jms.MessageListener. URL used by consumer is:
failover://(tcp://localhost:61616)?startupMaxReconnectAttempts=3&initialReconnectDelay=1000&timeout=500&maxReconnectDelay=1000&maxReconnectAttempts=-1
The problem is as follows:
At times a message is not delivered to any of the consumer. However, the
following messages are. I can see an entry for the corresponding message in
ACTIVEMQ_MSGS table. Once I restart ActiveMQ (without a restart of an
application holding the consumers), the missing message gets delivered. I
enclose the full init.out in which one can see what happens under the hood
of ActiveMQ (including the failing delivery of a message).
Let me do a short analysis for you. Once a message is sent with 5s delay an
internal job in ActiveMQ is scheduled for that:
2013-08-22 10:42:38,546 | DEBUG | ActiveMQ Transport:
tcp:///127.0.0.1:43716@61616 |
org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Scheduling Job
[id=ID:localhost.
localdomain-43080-1377160848385-1:1:5:1:1, startTime=Thu Aug 22 10:42:38
CEST 2013, delay=5000, period=0, repeat=0, nextTime=Thu Jan 01 01:00:00 CET
1970]
When the time comes, job is fired:
2013-08-22 10:42:43,006 | DEBUG | JobScheduler:JMS |
org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Firing Job
[id=ID:localhost.localdomain-43080-1377160848385-1:1:
5:1:1, startTime=Thu Aug 22 10:42:38 CEST 2013, delay=5000, period=0,
repeat=0, nextTime=Thu Aug 22 10:42:43 CEST 2013]
2013-08-22 10:42:43,008 | DEBUG | JobScheduler:JMS |
org.apache.activemq.broker.region.Queue | localhost Message
ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1 sent to que
ue://T
Then a bridging takes place - which *doesn't* occur for messages which
actually get delivered - which I don't understand:
2013-08-22 10:42:43,017 | DEBUG | ActiveMQ BrokerService[localhost] Task-5 |
org.apache.activemq.network.DemandForwardingBridgeSupport | bridging
(localhost -> localhost) ID:local
host.localdomain-43080-1377160848385-1:1:5:1:1, consumer:
ID:localhost.localdomain-38827-1377160835122-4:1:1:1, destination queue://T,
brokerPath: [ID:localhost.localdomain-38827-
1377160835122-1:1], message: ActiveMQObjectMessage {commandId = 16,
responseRequired = true, messageId =
ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1, originalDestinatio
n = null, originalTransactionId = null, producerId =
ID:localhost.localdomain-38827-1377160835122-4:2:1:1, destination =
queue://T, transactionId = null, expiration = 0, timestamp
= 1377160958535, arrival = 0, brokerInTime = 1377160963007, brokerOutTime =
1377160963009, correlationId = null, replyTo = null, persistent = true, type
= null, priority = 4, gro
upID = null, groupSequence = 0, targetConsumerId = null, compressed = false,
userID = null, content = org.apache.activemq.util.ByteSequence@4a6e0a9,
marshalledProperties = org.apa
che.activemq.util.ByteSequence@67e779a1, dataStructure = null,
redeliveryCounter = 0, size = 1117, properties =
{scheduledJobId=ID:localhost.localdomain-43080-1377160848385-1:1:5:
1:1}, readOnlyProperties = false, readOnlyBody = false, droppable = false}
After that a rescheduling of a job takes place:
2013-08-22 10:42:43,025 | DEBUG | ActiveMQ Transport:
tcp:///127.0.0.1:43630@61616 |
org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Scheduling Job
[id=ID:localhost.
localdomain-43080-1377160848385-1:1:5:1:1, startTime=Thu Aug 22 10:42:43
CEST 2013, delay=5000, period=0, repeat=0, nextTime=Thu Jan 01 01:00:00 CET
1970]
and firing of the job to send a message again:
2013-08-22 10:42:48,013 | DEBUG | JobScheduler:JMS |
org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Firing Job
[id=ID:localhost.localdomain-43080-1377160848385-1:1:
5:1:1, startTime=Thu Aug 22 10:42:43 CEST 2013, delay=5000, period=0,
repeat=0, nextTime=Thu Aug 22 10:42:48 CEST 2013]
2013-08-22 10:42:48,015 | DEBUG | JobScheduler:JMS |
org.apache.activemq.broker.region.Queue | localhost Message
ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1 sent to que
ue://T
However, no message is seen on the consumer side whatsoever and the entry
for the message remains in ACTIVEMQ_MSGS (no ACK?):
ID, CONTAINER, MSGID_PROD, MSGID_SEQR, EXPIRATION, MSG, PRIORITY, XID
'3', 'queue://T', 'ID:localhost.localdomain-43080-1377160848385-1:1:5:1',
'1', '0', BLOB, '0', NULL
For comparison, one can see a correct message sent at 10:41:38,054 in the
logs.
To sum up, the problem is that from time to time a message isn't delivered
by ActiveMQ. Is there something wrong with the configuration either on
server or consumer side? A doubtful bug in ActiveMQ? A hack for that is to
restart ActiveMQ for the missing messages to be delivered.
Moreover, for maintenance purposes - is there documentation / blog post /
article about how ACTIVEMQ_MSGS table works (apart from the short
description in 'ActiveMQ in Action' book)? What should be an action taken by
DBA if a number of entries in ACTIVEMQ_MSGS table grow?
I'd be grateful for any support since I'm beginning to feel helpless.
Cheers,
Tomek
activemq.xml
<http://activemq.2283324.n4.nabble.com/file/n4670572/activemq.xml>
init.out <http://activemq.2283324.n4.nabble.com/file/n4670572/init.out>
--
View this message in context: http://activemq.2283324.n4.nabble.com/No-message-delivery-vs-ACTIVEMQ-MSGS-tp4670572.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: No message delivery vs ACTIVEMQ_MSGS
Posted by tomek <to...@seamless.se>.
Hi,
adding enableAudit="false" in policyEntry works like a charm. Thanks a lot!
Having known it's enableAudit's responsibility I found an article describing
a similar problem to mine:
http://tmielke.blogspot.de/2012/03/i-have-messages-on-queue-but-they-dont.html
.
Cheers,
Tomek
--
View this message in context: http://activemq.2283324.n4.nabble.com/No-message-delivery-vs-ACTIVEMQ-MSGS-tp4670572p4670575.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: No message delivery vs ACTIVEMQ_MSGS
Posted by Gary Tully <ga...@gmail.com>.
enable TRACE level logging, it will give more information.
it seems that the message audit on the cursor may see the second
scheduled message as a duplicate. The audit is
not persisted so it would explain why a restart helps.
Using a destination policy entry, disable the message audit:
<policyEntry queue="..." enableAudit="false" .. />
The other option is that the message is inflight pending an ack, but
in that case it would be visible in the consumer jmx view as inflight.
On 22 August 2013 10:47, tomek <to...@seamless.se> wrote:
> Hi,
>
> I'm working on ActiveMQ 5.8.0 with MySQL as a data source. The configuration
> of ActiveMQ is attached (activemq.xml). It is used in a basic scenario: a
> producer sends a short message (JSON object with 2 fields) with 5s delay to
> queue T on which 3 consumers listen. The consumers are created using plain
> Java API:
>
>
> for (int i = 0; i < numberOfConsumer; i++)
> {
> Session session = connection.createSession(false,
> Session.AUTO_ACKNOWLEDGE);
>
> Destination destination = session.createQueue(queueName);
>
> MessageConsumer consumer = session.createConsumer(destination);
> MyConsumer myConsumer = new MyConsumer();
> consumer.setMessageListener(myConsumer);
> connection.setExceptionListener(myConsumer);
>
> consumers.add(invoiceConsumer);
>
> }
>
>
> MyConsumer class implements both javax.jms.ExceptionListener and
> javax.jms.MessageListener. URL used by consumer is:
> failover://(tcp://localhost:61616)?startupMaxReconnectAttempts=3&initialReconnectDelay=1000&timeout=500&maxReconnectDelay=1000&maxReconnectAttempts=-1
>
> The problem is as follows:
> At times a message is not delivered to any of the consumer. However, the
> following messages are. I can see an entry for the corresponding message in
> ACTIVEMQ_MSGS table. Once I restart ActiveMQ (without a restart of an
> application holding the consumers), the missing message gets delivered. I
> enclose the full init.out in which one can see what happens under the hood
> of ActiveMQ (including the failing delivery of a message).
>
> Let me do a short analysis for you. Once a message is sent with 5s delay an
> internal job in ActiveMQ is scheduled for that:
>
> 2013-08-22 10:42:38,546 | DEBUG | ActiveMQ Transport:
> tcp:///127.0.0.1:43716@61616 |
> org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Scheduling Job
> [id=ID:localhost.
> localdomain-43080-1377160848385-1:1:5:1:1, startTime=Thu Aug 22 10:42:38
> CEST 2013, delay=5000, period=0, repeat=0, nextTime=Thu Jan 01 01:00:00 CET
> 1970]
>
> When the time comes, job is fired:
>
> 2013-08-22 10:42:43,006 | DEBUG | JobScheduler:JMS |
> org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Firing Job
> [id=ID:localhost.localdomain-43080-1377160848385-1:1:
> 5:1:1, startTime=Thu Aug 22 10:42:38 CEST 2013, delay=5000, period=0,
> repeat=0, nextTime=Thu Aug 22 10:42:43 CEST 2013]
> 2013-08-22 10:42:43,008 | DEBUG | JobScheduler:JMS |
> org.apache.activemq.broker.region.Queue | localhost Message
> ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1 sent to que
> ue://T
>
> Then a bridging takes place - which *doesn't* occur for messages which
> actually get delivered - which I don't understand:
>
> 2013-08-22 10:42:43,017 | DEBUG | ActiveMQ BrokerService[localhost] Task-5 |
> org.apache.activemq.network.DemandForwardingBridgeSupport | bridging
> (localhost -> localhost) ID:local
> host.localdomain-43080-1377160848385-1:1:5:1:1, consumer:
> ID:localhost.localdomain-38827-1377160835122-4:1:1:1, destination queue://T,
> brokerPath: [ID:localhost.localdomain-38827-
> 1377160835122-1:1], message: ActiveMQObjectMessage {commandId = 16,
> responseRequired = true, messageId =
> ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1, originalDestinatio
> n = null, originalTransactionId = null, producerId =
> ID:localhost.localdomain-38827-1377160835122-4:2:1:1, destination =
> queue://T, transactionId = null, expiration = 0, timestamp
> = 1377160958535, arrival = 0, brokerInTime = 1377160963007, brokerOutTime =
> 1377160963009, correlationId = null, replyTo = null, persistent = true, type
> = null, priority = 4, gro
> upID = null, groupSequence = 0, targetConsumerId = null, compressed = false,
> userID = null, content = org.apache.activemq.util.ByteSequence@4a6e0a9,
> marshalledProperties = org.apa
> che.activemq.util.ByteSequence@67e779a1, dataStructure = null,
> redeliveryCounter = 0, size = 1117, properties =
> {scheduledJobId=ID:localhost.localdomain-43080-1377160848385-1:1:5:
> 1:1}, readOnlyProperties = false, readOnlyBody = false, droppable = false}
>
> After that a rescheduling of a job takes place:
> 2013-08-22 10:42:43,025 | DEBUG | ActiveMQ Transport:
> tcp:///127.0.0.1:43630@61616 |
> org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Scheduling Job
> [id=ID:localhost.
> localdomain-43080-1377160848385-1:1:5:1:1, startTime=Thu Aug 22 10:42:43
> CEST 2013, delay=5000, period=0, repeat=0, nextTime=Thu Jan 01 01:00:00 CET
> 1970]
>
> and firing of the job to send a message again:
> 2013-08-22 10:42:48,013 | DEBUG | JobScheduler:JMS |
> org.apache.activemq.store.kahadb.scheduler.JobSchedulerImpl | Firing Job
> [id=ID:localhost.localdomain-43080-1377160848385-1:1:
> 5:1:1, startTime=Thu Aug 22 10:42:43 CEST 2013, delay=5000, period=0,
> repeat=0, nextTime=Thu Aug 22 10:42:48 CEST 2013]
> 2013-08-22 10:42:48,015 | DEBUG | JobScheduler:JMS |
> org.apache.activemq.broker.region.Queue | localhost Message
> ID:localhost.localdomain-43080-1377160848385-1:1:5:1:1 sent to que
> ue://T
>
> However, no message is seen on the consumer side whatsoever and the entry
> for the message remains in ACTIVEMQ_MSGS (no ACK?):
> ID, CONTAINER, MSGID_PROD, MSGID_SEQR, EXPIRATION, MSG, PRIORITY, XID
> '3', 'queue://T', 'ID:localhost.localdomain-43080-1377160848385-1:1:5:1',
> '1', '0', BLOB, '0', NULL
>
> For comparison, one can see a correct message sent at 10:41:38,054 in the
> logs.
>
> To sum up, the problem is that from time to time a message isn't delivered
> by ActiveMQ. Is there something wrong with the configuration either on
> server or consumer side? A doubtful bug in ActiveMQ? A hack for that is to
> restart ActiveMQ for the missing messages to be delivered.
>
> Moreover, for maintenance purposes - is there documentation / blog post /
> article about how ACTIVEMQ_MSGS table works (apart from the short
> description in 'ActiveMQ in Action' book)? What should be an action taken by
> DBA if a number of entries in ACTIVEMQ_MSGS table grow?
>
> I'd be grateful for any support since I'm beginning to feel helpless.
>
> Cheers,
>
> Tomek
>
> activemq.xml
> <http://activemq.2283324.n4.nabble.com/file/n4670572/activemq.xml>
> init.out <http://activemq.2283324.n4.nabble.com/file/n4670572/init.out>
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/No-message-delivery-vs-ACTIVEMQ-MSGS-tp4670572.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
--
http://redhat.com
http://blog.garytully.com