activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Marek Slama (Issue Comment Edited) (JIRA)" <j...@apache.org>
Subject [jira] [Issue Comment Edited] (AMQ-3728) Broker stops to accept messages
Date Thu, 23 Feb 2012 09:15:49 GMT

    [ 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

        

Mime
View raw message