activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Frans Henskens <fhensk...@yahoo.com.INVALID>
Subject Ongoing queue troubles
Date Fri, 20 Oct 2017 12:43:45 GMT
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=ffffffb7ffffffee4c385f10047544d4944000000000000000000000000000000000000000000000000000,length=64,branchId=1000ffffff9affffffee4c385f10044000000000000000000000000000000000000000000000000000,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=ffffffb7ffffffee4c385f10047544d4944000000000000000000000000000000000000000000000000000,branchId=1000ffffff9affffffee4c385f10044000000000000000000000000000000000000000000000000000],connection=ActiveMQConnection
{id=ID:henskens-51054-1508478087236-9:1,clientId=XMLEventRedirectorMDB,started=true}} started
XA transaction XID:[1197822575,globalId=ffffffb7ffffffee4c385f10047544d4944000000000000000000000000000000000000000000000000000,branchId=1000ffffff9affffffee4c385f10044000000000000000000000000000000000000000000000000000]
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=ffffffb6ffffffee4c385f10047544d4944000000000000000000000000000000000000000000000000000,branchId=1000ffffff9affffffee4c385f10044000000000000000000000000000000000000000000000000000],
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=ffffffb7ffffffee4c385f10047544d4944000000000000000000000000000000000000000000000000000,branchId=1000ffffff9affffffee4c385f10044000000000000000000000000000000000000000000000000000]
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=ffffffb31752385f10047544d4944000000000000000000000000000000000000000000000000000,branchId=1000ffffffb31752385f10044000000000000000000000000000000000000000000000000000],
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

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message