You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Marek Slama (Issue Comment Edited) (JIRA)" <ji...@apache.org> on 2012/02/23 10:15:49 UTC
[jira] [Issue Comment Edited] (AMQ-3728) Broker stops to accept
messages
[ https://issues.apache.org/jira/browse/AMQ-3728?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13214484#comment-13214484 ]
Marek Slama edited comment on AMQ-3728 at 2/23/12 9:14 AM:
-----------------------------------------------------------
So I tested last snapshot (I downloaded latest binary broker build and for my producer I set URL for ActiveMQ snapshot repository), I reviewed my code to make sure Session is used from one thread only, I cache producers (I have 3 producers for 3 topics), I even created Session and MessageProducers in worker thread and then call send from this worker thread. Still after 23000 messages sent it again fails. This time there is no subscriber. Only producer and broker. This time it starts with:
{code}
2012-02-22 21:37:43,224 ERROR [com.idc.publishing.metacop.jms.JmsProducer] (JmsProducerWorker-1) MetaCop Error > Could not send message to JMS topic:idc.publishing.metacop.Company2: javax.jms.JMSException: java.io.EOFException
at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1360) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1340) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1777) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:247) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241) [activemq-core-5.6-20120104.153301-1.jar:]
at com.idc.publishing.metacop.jms.JmsProducer$3.run(JmsProducer.java:210) [classes:]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_30]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_30]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [:1.6.0_30]
Caused by: java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:375) [:1.6.0_30]
at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:275) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:229) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:221) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204) [activemq-core-5.6-20120104.153301-1.jar:]
... 1 more
{code}
It is after I sent about 110000 messages successfully.
After a while it tries to recover:
{code}
2012-02-22 21:37:43,698 INFO [org.springframework.jms.listener.SimpleMessageListenerContainer] (ActiveMQ Connection Executor: tcp://usfr-cmsnpdev.insideidc.com/10.1.4.42:61616) Trying to recover from JMS Connection exception: javax.jms.JMSException: java.io.EOFException
2012-02-22 21:37:43,698 DEBUG [com.idc.publishing.metacop.repository.DocumentRepositoryImpl] (CalaisWorker-11) Update classification with 38 categories for document:HW62R9
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) Exception in thread "InactivityMonitor WriteCheck" java.util.concurrent.RejectedExecutionException
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:1768)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:767)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:658)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.transport.AbstractInactivityMonitor.writeCheck(AbstractInactivityMonitor.java:142)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.transport.AbstractInactivityMonitor$2.run(AbstractInactivityMonitor.java:111)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
2012-02-22 21:37:43,720 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.TimerThread.mainLoop(Timer.java:512)
2012-02-22 21:37:43,720 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.TimerThread.run(Timer.java:462)
{code}
and next session gets closed:
{code}
2012-02-22 21:37:45,229 ERROR [com.idc.publishing.metacop.jms.JmsProducer] (JmsProducerWorker-1) MetaCop Error > Could not send message to JMS topic:idc.publishing.metacop.Document2: javax.jms.IllegalStateException: The Session is closed
at org.apache.activemq.ActiveMQSession.checkClosed(ActiveMQSession.java:727) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.configureMessage(ActiveMQSession.java:715) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.createTextMessage(ActiveMQSession.java:428) [activemq-core-5.6-20120104.153301-1.jar:]
at com.idc.publishing.metacop.jms.JmsProducer$3.run(JmsProducer.java:209) [classes:]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_30]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_30]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [:1.6.0_30]
{code}
was (Author: mslama):
So I tested last snapshot, I reviewed my code to make sure Session is used from one thread only, I cache producers (I have 3 producers for 3 topics), I even created Session and MessageProducers in worker thread and then call send from this worker thread. Still after 23000 messages sent it again fails. This time there is no subscriber. Only producer and broker. This time it starts with:
{code}
2012-02-22 21:37:43,224 ERROR [com.idc.publishing.metacop.jms.JmsProducer] (JmsProducerWorker-1) MetaCop Error > Could not send message to JMS topic:idc.publishing.metacop.Company2: javax.jms.JMSException: java.io.EOFException
at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1360) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1340) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1777) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:247) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241) [activemq-core-5.6-20120104.153301-1.jar:]
at com.idc.publishing.metacop.jms.JmsProducer$3.run(JmsProducer.java:210) [classes:]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_30]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_30]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [:1.6.0_30]
Caused by: java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:375) [:1.6.0_30]
at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:275) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:229) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:221) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204) [activemq-core-5.6-20120104.153301-1.jar:]
... 1 more
{code}
It is after I sent about 110000 messages successfully.
After a while it tries to recover:
{code}
2012-02-22 21:37:43,698 INFO [org.springframework.jms.listener.SimpleMessageListenerContainer] (ActiveMQ Connection Executor: tcp://usfr-cmsnpdev.insideidc.com/10.1.4.42:61616) Trying to recover from JMS Connection exception: javax.jms.JMSException: java.io.EOFException
2012-02-22 21:37:43,698 DEBUG [com.idc.publishing.metacop.repository.DocumentRepositoryImpl] (CalaisWorker-11) Update classification with 38 categories for document:HW62R9
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) Exception in thread "InactivityMonitor WriteCheck" java.util.concurrent.RejectedExecutionException
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:1768)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:767)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:658)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.transport.AbstractInactivityMonitor.writeCheck(AbstractInactivityMonitor.java:142)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.transport.AbstractInactivityMonitor$2.run(AbstractInactivityMonitor.java:111)
2012-02-22 21:37:43,705 ERROR [stderr] (InactivityMonitor WriteCheck) at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
2012-02-22 21:37:43,720 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.TimerThread.mainLoop(Timer.java:512)
2012-02-22 21:37:43,720 ERROR [stderr] (InactivityMonitor WriteCheck) at java.util.TimerThread.run(Timer.java:462)
{code}
and next session gets closed:
{code}
2012-02-22 21:37:45,229 ERROR [com.idc.publishing.metacop.jms.JmsProducer] (JmsProducerWorker-1) MetaCop Error > Could not send message to JMS topic:idc.publishing.metacop.Document2: javax.jms.IllegalStateException: The Session is closed
at org.apache.activemq.ActiveMQSession.checkClosed(ActiveMQSession.java:727) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.configureMessage(ActiveMQSession.java:715) [activemq-core-5.6-20120104.153301-1.jar:]
at org.apache.activemq.ActiveMQSession.createTextMessage(ActiveMQSession.java:428) [activemq-core-5.6-20120104.153301-1.jar:]
at com.idc.publishing.metacop.jms.JmsProducer$3.run(JmsProducer.java:209) [classes:]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_30]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_30]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [:1.6.0_30]
{code}
> Broker stops to accept messages
> -------------------------------
>
> Key: AMQ-3728
> URL: https://issues.apache.org/jira/browse/AMQ-3728
> Project: ActiveMQ
> Issue Type: Bug
> Affects Versions: 5.5.0
> Environment: Linux, 64bit, JDK 6u30 64bit
> Reporter: Marek Slama
>
> I have following configuration:
> 1.One producer
> 2.One broker on the same machine as producer.
> 3.One offline durable subscriber but I have enough storage size so it should not overflow.
> I run our import test and it sends about 10 messages/s. After some hours of run I start to get:
> many
> {code}javax.jms.JMSException: org.apache.activemq.transport.RequestTimedOutIOException{code}
> (I set send timeout 2s to avoid infinite block in case that broker storage is full. So first question is why it happens when there should be enough space. I will provide my broker configuration below.)
> Then I get:
> {code}
> javax.jms.JMSException: Cannot send, channel has already failed: usfr-cmsnpdev.insideidc.com/10.1.4.42:61616
> javax.jms.JMSException: Cannot send, channel has already failed: usfr-cmsnpdev.insideidc.com/10.1.4.42:61616
> (ActiveMQ Connection Executor: tcp://usfr-cmsnpdev.insideidc.com/10.1.4.42:61616) Failed to send message.: javax.jms.JMSException: Broken pipe
> {code}
> some more
> {code}
> javax.jms.JMSException: Cannot send, channel has already failed: usfr-cmsnpdev.insideidc.com/10.1.4.42:61616
> {code}
> and then all the time:
> {code}
> javax.jms.IllegalStateException: The Session is closed
> {code}
> I have simple producer code. It is Spring bean. I create connection and session when bean is created. For every send message I create producer and close it:
> {code}
> //Init code
> connection = connectionFactory.createConnection();
> connection.setExceptionListener(new ExceptionListener() {
> public void onException(JMSException ex) {
> logger.error("Failed to send message.", ex);
> }
> });
> session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
> ....
> //Send code
> private void sendMessage(String xmlMessage, Topic topic, String containerId) {
> MessageProducer producer = null;
> try {
> // Create the producer.
> producer = session.createProducer(topic);
> TextMessage txtMessage = session.createTextMessage(xmlMessage);
> producer.send(txtMessage);
> } catch (JMSException ex) {
> logger.error("", ex);
> } finally {
> try {
> if (producer != null) {
> producer.close();
> }
> } catch (JMSException ex) {
> }
> }
> }
> {code}
> Use default connection factory:
> {code}
> <bean id="idc_metacop_jmsFactory.prototype"
> class="org.apache.activemq.ActiveMQConnectionFactory"
> abstract="true">
> <property name="brokerURL" value="${metacop.jms.brokerURL}"/>
> <property name="sendTimeout" value="2000"/>
> </bean>
> {code}
> Log from broker:
> {code}
> 2012-02-17 21:55:40,389 | INFO | Transport failed: org.apache.activemq.transport.InactivityIOException: Channel was inactive for too (>30000) long: /10.1.4.42:56166 | org.apache.activemq.broker.TransportConnection.Transport | InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@fcc9c76
> 2012-02-17 21:55:42,445 | INFO | Transport failed: org.apache.activemq.transport.InactivityIOException: Channel was inactive for too (>30000) long: /10.1.4.42:39395 | org.apache.activemq.broker.TransportConnection.Transport | InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@fcc9c76
> {code}
> Broker configuration:
> {code}
> <broker xmlns="http://activemq.apache.org/schema/core" brokerName="localhost" dataDirectory="${activemq.base}/data" destroyApplicationContextOnStop="true">
> <destinationPolicy>
> <policyMap>
> <policyEntries>
> <policyEntry topic=">" producerFlowControl="true" memoryLimit="200mb">
> </policyEntry>
> <policyEntry queue=">" producerFlowControl="true" memoryLimit="200mb">
> </policyEntry>
> </policyEntries>
> </policyMap>
> </destinationPolicy>
> <managementContext>
> <managementContext createConnector="false"/>
> </managementContext>
> <persistenceAdapter>
> <kahaDB directory="${activemq.base}/data/kahadb"/>
> </persistenceAdapter>
> <systemUsage>
> <systemUsage>
> <memoryUsage>
> <memoryUsage limit="500 mb"/>
> </memoryUsage>
> <storeUsage>
> <storeUsage limit="2 gb"/>
> </storeUsage>
> <tempUsage>
> <tempUsage limit="2 gb"/>
> </tempUsage>
> </systemUsage>
> </systemUsage>
> <transportConnectors>
> <transportConnector name="openwire" uri="tcp://0.0.0.0:61616"/>
> </transportConnectors>
> </broker>
> {code}
> I can provide full call stacks if necessary. One thing which comes to my mind: When I have just one connection is call of producer.send thread safe? I do not have any synchronization there.
> BTW is there any way how to purge even undelivered messages from broker storage? Or how to monitor number of messages in storage? I tried to delete offline durable subscribers from Web Admin but data folder size does not change but I have no way how to see if messages was really removed from storage (and db is not compacted only or if messages stay in storage.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira