I see the messages enqueueing. I can see a consumer attached to the command
queue. Dispatch count and dequeued count stay at 0.
Does that sound right?
Thanks,Frans On Saturday, 21 October 2017, 12:13:24 am AEDT, Tim Bain
<tb...@alumni.duke.edu> wrote:
First figure out if your problem is that the messages are not getting into the
CommandQueue or if it's that they're not getting from there to the consumer. To
do that, attach a JMX viewer such as JConsole to the broker process, and then
in the MBeans tab navigate down to the MBean for the queue and click on it.
You'll see a bunch of stats, including EnqueueCount (the total number of
messages sent to the queue; if this is 0, your problem is the publisher and you
should step through it with a debugger), InFlightCount (the number of messages
that have been dispatched to the consumer but not yet acknowledged; if this is
non-zero, you need to figure out what the consumer is doing and why it's not
acking the messages), and DequeueCount (if it matches the EnqueueCount, then
all messages have been consumed, and you need to figure out why you're not
seeing your log line).
Then expand the queue's MBean in the tree and expand the Consumers node and see
if you have zero, one, or more connected consumers, and if they appear to be
the right ones (IP/port matches the connection from your app server).
Tim
On Oct 20, 2017 6:44 AM, "Frans Henskens" <fhensk...@yahoo.com.invalid> wrote:
Hi all,
Apologies. I was posting directly in the nabble forum area, which is probably
on a lot of spam folders.
I've configured a couple of topics and a queue. The topics work fine, but I'm
having some trouble activating the queue.
If anyone can spot what I've done wrong, it would be greatly appreciated!
Producer (identical to topic producers, bar using queue):
public synchronized void queue( final InitialContext context, final boolean
postpone ) throws JMSException,
NamingException
{
final ConnectionFactory connectionFactory =
(ConnectionFactory) Application.getInitialContext( ).lookup(
"openejb:Resource/ JmsConnectionFactory" );
final Connection connection = connectionFactory. createConnection();
connection.start();
final Session session =
connection.createSession( false, Session.AUTO_ACKNOWLEDGE);
final Queue commandQueue =
(Queue)Application. getInitialContext().lookup(
"openejb:Resource/ CommandQueue" );
final MessageProducer producer = session.createProducer( commandQueue );
final ObjectMessage message = session.createObjectMessage( this );
if ( postpone )
{
message.setLongProperty(
ScheduledMessage.AMQ_ SCHEDULED_DELAY,
getRetryIntervalMinutes() * 60000 );
}
producer.send( message );
try { producer.close(); } catch ( final Exception e ) {}
try { session.close(); } catch ( final Exception e ) {}
try { connection.close(); } catch ( final Exception e ) {}
}
Consumer (also largely the same to topic consumers):
@MessageDriven(name = "CommandExecutorMDB", activationConfig = {
@ActivationConfigProperty( propertyName = "destinationType",
propertyValue = "javax.jms.Queue"),
@ActivationConfigProperty( propertyName = "destination", propertyValue
= "CommandQueue"),
@ActivationConfigProperty( propertyName = "acknowledgeMode",
propertyValue = "Auto-acknowledge") })
@LocalClient
public class CommandExecutorMDB implements MessageListener
{
@Resource
private ConnectionFactory myConnectionFactory;
@Resource( name="CommandQueue" )
private Queue myCommandQueue;
/* (non-Javadoc)
* @see javax.jms.MessageListener# onMessage(javax.jms.Message)
*/
@Override
public void onMessage( final Message msg )
{
DefaultLog.getDefaultLog(). logInfo( "CommandQueue received message" );
// Never reached, sadly
try
{
Command command = null;
// We got a message, try to read it
try
{
command = Command.read( msg );
if ( command == null )
{
throw new Exception(
"Null message received on command queue" );
}
}
catch ( final Exception e )
{
DefaultLog.getDefaultLog(). logError( "Error reading message
from JMS queue. Committing the transaction and trying again.", e );
}
// attempt the command.
command.attempt( Application.getInitialContext( ) );
}
catch ( final Exception e )
{
DefaultLog.getDefaultLog(). logError( "Internal error while
attempting Command. ", e );
}
}}
Here's log entries showing ActiveMQ activating the MDBs20-Oct-2017 16:14:15.173
INFO [localhost-startStop-1] org.apache.openejb.assembler.
classic.Assembler.startEjbs Started Ejb(deployment-id= XMLEventRedirectorMDB,
ejb-name= XMLEventRedirectorMDB, container= MessageDrivenContainer)
20-Oct-2017 16:14:15.173 INFO [localhost-startStop-1]
org.apache.openejb.assembler. classic.Assembler.startEjbs Started
Ejb(deployment-id= CommandExecutorMDB, ejb-name=CommandExecutorMDB, container=
MessageDrivenContainer)
Here's VMTransport adding connections to the consumers (CommandExecutorMDB
doesn't seem to show up here explicitly. Perhaps I did something wrong there?
henskens-50366-1508476452803- 8:1 only shows up once here in the logs)
20-Oct-2017 16:14:17.340 FINE [ActiveMQ VMTransport: vm://broker#1-1]
org.apache.activemq.broker. TransportConnection. processAddConnection Setting
up new connection id: ID:henskens-50366- 1508476452803-7:1, address:
vm://broker#0, info: ConnectionInfo {commandId = 1, responseRequired = true,
connectionId = ID:henskens-50366- 1508476452803-7:1, clientId =
XMLEventRedirectorMDB, clientIp = null, userName = null, password = *****,
brokerPath = null, brokerMasterConnector = false, manageable = true,
clientMaster = true, faultTolerant = false, failoverReconnect = false}
20-Oct-2017 16:14:17.340 FINE [ActiveMQ VMTransport: vm://broker#5-1]
org.apache.activemq.broker. TransportConnection. processAddConnection Setting
up new connection id: ID:henskens-50366- 1508476452803-9:1, address:
vm://broker#4, info: ConnectionInfo {commandId = 1, responseRequired = true,
connectionId = ID:henskens-50366- 1508476452803-9:1, clientId =
ID:henskens-50366- 1508476452803-8:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false, manageable
= true, clientMaster = true, faultTolerant = false, failoverReconnect = false}
hen the topic is fired, there are initial calls about setting up a transaction
and registering with the consumer before marshalling the object:20-Oct-2017
16:41:53.266 FINE [JmsResourceAdapter-worker- - 6] org.apache.activemq.
TransactionContext.start Start: [Xid:globalId= ffffffb7ffffffee4c385f10047544
d49440000000000000000000000000 00000000000000000000000000, length=64,branchId=
1000ffffff9affffffee4c385f1004 400000000000000000000000000000
0000000000000000000000,length= 64], flags: TMNOFLAGS
20-Oct-2017 16:41:53.266 FINE [JmsResourceAdapter-worker- - 6]
org.apache.activemq. TransactionContext.setXid TransactionContext{
transactionId=XID:[1197822575, globalId= ffffffb7ffffffee4c385f10047544
d49440000000000000000000000000 00000000000000000000000000, branchId=
1000ffffff9affffffee4c385f1004 400000000000000000000000000000
0000000000000000000000], connection=ActiveMQConnection {id=ID:henskens-51054-
1508478087236-9:1,clientId= XMLEventRedirectorMDB,started= true}} started XA
transaction XID:[1197822575,globalId= ffffffb7ffffffee4c385f10047544
d49440000000000000000000000000 00000000000000000000000000, branchId=
1000ffffff9affffffee4c385f1004 400000000000000000000000000000
0000000000000000000000]
20-Oct-2017 16:41:53.267 FINEST [JmsResourceAdapter-worker- - 6]
org.apache.activemq. ActiveMQSession.run ActiveMQSession {id=ID:henskens-51054-
1508478087236-9:1:1,started= true} java.lang.Object@a79c9a2
onMessage(ID:henskens-51054- 1508478087236-13:1:3:1:1)
20-Oct-2017 16:41:53.267 FINEST [JmsResourceAdapter-worker- - 6]
org.apache.activemq.ra. MessageEndpointProxy.onMessage Invoking
MessageEndpoint.onMethod()
20-Oct-2017 16:41:53.267 FINEST [Thread-31] org.apache.activemq.
ActiveMQMessageConsumer. dequeue ID:henskens-51054- 1508478087236-11:1:1:1
received message: MessageDispatch {commandId = 8, responseRequired = false,
consumerId = ID:henskens-51054- 1508478087236-11:1:1:1, destination =
topic://EventTopic, message = ActiveMQObjectMessage {commandId = 31,
responseRequired = false, messageId = ID:henskens-51054-
1508478087236-13:1:3:1:1, originalDestination = null, originalTransactionId =
null, producerId = ID:henskens-51054- 1508478087236-13:1:3:1, destination =
topic://EventTopic, transactionId = XID:[1197822575,globalId=
ffffffb6ffffffee4c385f10047544 d49440000000000000000000000000
00000000000000000000000000, branchId= 1000ffffff9affffffee4c385f1004
400000000000000000000000000000 0000000000000000000000], expiration = 0,
timestamp = 1508478113231, arrival = 0, brokerInTime = 1508478113233,
brokerOutTime = 1508478113263, correlationId = null, replyTo = null, persistent
= true, type = 9, priority = 4, groupID = null, groupSequence = 0,
targetConsumerId = null, compressed = false, userID = null, content =
org.apache.activemq.util. ByteSequence@3dd234c3, marshalledProperties = null,
dataStructure = null, redeliveryCounter = 0, size = 1495, properties = null,
readOnlyProperties = true, readOnlyBody = true, droppable = false,
jmsXGroupFirstForConsumer = false}, redeliveryCounter = 0}
20-Oct-2017 16:41:53.267 FINEST [ActiveMQ VMTransport: vm://broker#3-1]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#3
20-Oct-2017 16:41:53.269 FINE [ActiveMQ VMTransport: vm://broker#3-1]
org.apache.activemq. transaction.XATransaction.< init> XA Transaction new/begin
: XID:[1197822575,globalId= ffffffb7ffffffee4c385f10047544
d49440000000000000000000000000 00000000000000000000000000, branchId=
1000ffffff9affffffee4c385f1004 400000000000000000000000000000
0000000000000000000000]
20-Oct-2017 16:41:53.271 FINEST [ActiveMQ VMTransport: vm://broker#3-1]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: vm://broker#3
The event triggers a message, sending it to CommandQueue... not much
happens:20-Oct-2017 16:41:53.276 FINEST [ActiveMQ VMTransport: vm://broker#7-1]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#7
20-Oct-2017 16:41:53.277 FINEST [ActiveMQ VMTransport: vm://broker#7-1]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 1 -
vm://broker#7
20-Oct-2017 16:41:53.278 FINE [ActiveMQ VMTransport: vm://broker#7-1]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 16:41:53.278 FINE [ActiveMQ VMTransport: vm://broker#7-1]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 16:41:53.278 FINEST [ActiveMQ VMTransport: vm://broker#7-1]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: vm://broker#7
20-Oct-2017 16:41:53.278 FINEST [ActiveMQ VMTransport: vm://broker#6-1]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#6
Lines about marshalling the message, then:
20-Oct-2017 17:08:38.227 FINEST [Thread-31] org.apache.activemq.
ActiveMQSession.send ID:qv-henskens-51583- 1508478425436-11:1:10 sending
message: ActiveMQObjectMessage {commandId = 0, responseRequired = false,
messageId = ID:qv-henskens-51583- 1508478425436-11:1:10:1:1,
originalDestination = null, originalTransactionId = null, producerId =
ID:qv-henskens-51583- 1508478425436-11:1:10:1, destination =
queue://CommandQueue, transactionId = XID:[1197822575,globalId=
ffffffb31752385f10047544d49440 000000000000000000000000000000
00000000000000000000,branchId= 1000ffffffb31752385f1004400000
000000000000000000000000000000 0000000000000000], expiration = 0, timestamp =
1508479718227, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId
= null, replyTo = null, persistent = true, type = null, priority = 4, groupID =
null, groupSequence = 0, targetConsumerId = null, compressed = false, userID =
null, content = org.apache.activemq.util. ByteSequence@1cc17480,
marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size
= 0, properties = null, readOnlyProperties = true, readOnlyBody = true,
droppable = false, jmsXGroupFirstForConsumer = false}
20-Oct-2017 17:08:38.237 FINEST [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#7
20-Oct-2017 17:08:38.257 FINEST [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 1 -
vm://broker#7
20-Oct-2017 17:08:38.257 FINEST [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#9
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.broker. jmx.ManagementContext. unregisterMBean
Unregistering MBean org.apache.activemq:type= Broker,brokerName=broker,
destinationType=Queue, destinationName=CommandQueue,
endpoint=Producer,clientId=ID_ qv-henskens-51583-
1508478425436-10_1,producerId= ID_qv-henskens-51583- 1508478425436-11_1_10_1
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.broker. TransportConnection. processAddConnection Setting
up new connection id: ID:qv-henskens-51583- 1508478425436-13:1, address:
vm://broker#8, info: ConnectionInfo {commandId = 76, responseRequired = true,
connectionId = ID:qv-henskens-51583- 1508478425436-13:1, clientId =
ID:qv-henskens-51583- 1508478425436-12:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false, manageable
= true, clientMaster = true, faultTolerant = false, failoverReconnect = false}
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 17:08:38.257 FINE [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.broker. TransportConnector. getPublishableConnectString
Publishing: vm://broker for broker transport URI: vm://broker
20-Oct-2017 17:08:38.257 FINEST [ActiveMQ VMTransport: vm://broker#7-7]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: vm://broker#7
20-Oct-2017 17:08:38.257 FINEST [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.thread. TaskRunnerFactory$1.newThread Created
thread[ActiveMQ VMTransport: vm://broker#8-7]: Thread[ActiveMQ VMTransport:
vm://broker#8-7,5,main]
20-Oct-2017 17:08:38.257 FINEST [ActiveMQ VMTransport: vm://broker#9-8]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: vm://broker#9
20-Oct-2017 17:08:38.267 FINEST [ActiveMQ BrokerService[broker] Task-15]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
Transport Connection to: vm://broker#8
20-Oct-2017 17:08:38.267 FINEST [ActiveMQ VMTransport: vm://broker#7-8]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 0 -
vm://broker#7
20-Oct-2017 17:08:38.267 FINEST [ActiveMQ VMTransport: vm://broker#7-8]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: vm://broker#7
20-Oct-2017 17:08:38.277 FINEST [ActiveMQ BrokerService[broker] Task-15]
org.apache.activemq.thread. PooledTaskRunner.runTask Running task iteration 1 -
Transport Connection to: vm://broker#8
20-Oct-2017 17:08:38.277 FINEST [ActiveMQ BrokerService[broker] Task-15]
org.apache.activemq.thread. PooledTaskRunner$1.run Run task done: Transport
Connection to: vm://broker#8
20-Oct-2017 17:08:38.317 FINE [ActiveMQ Broker[broker] Scheduler]
org.apache.activemq.broker. region.Queue.expireMessages queue://CommandQueue
expiring messages ..
20-Oct-2017 17:08:38.317 FINEST [ActiveMQ Broker[broker] Scheduler]
org.apache.activemq.broker. region.Queue. shouldPageInMoreForBrowse max 400,
alreadyPagedIn 0, messagesCount 0, memoryUsage 0%
Any ideas how I might have stuffed this up? It would be much appreciated!
Cheers,Frans
