activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From GaryG <ggive...@us.ibm.com>
Subject Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException
Date Thu, 30 Jul 2009 20:07:17 GMT

I just did another test - where I didn't have any clients connected to JMS -
just ran the server by itself.

Same problem.  It restarted even though no message were coming across.

So, definitely something causing the server to die.


GaryG wrote:
> 
> On the client side, i'm seeing this:
> 
> 2009-07-30 19:12:55,472 [ActiveMQ Connection Worker:
> tcp://server2/1.1.1.18:61616] ERROR jms_comm - FactoryUtil.onException
> javax.jms.JMSException: java.io.EOFException
>         at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:49)
>         at
> org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1773)
>         at
> org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1790)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:99)
>         at
> org.apache.activemq.transport.ResponseCorrelator.onException(ResponseCorrelator.java:114)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:99)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:99)
>         at
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:152)
>         at
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:244)
>         at
> org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:96)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:189)
>         at java.lang.Thread.run(Thread.java:619)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readInt(DataInputStream.java:375)
>         at
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:210)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:202)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
>         ... 1 more
> 
> So, perhaps there's some subtle change in how API should be used in 5.2.0
> version that makes the server die when we send messages?
> 
> We're using simple MapMessages to send all our data.  
> 
> MapMessage msg = session.createMapMessage();
> 
> putting some string and int values into it, then using
> 
> MessageProducer mp = .....
> mp.send(msg);
> 
> I'm still stumped...
> 
> 
> 
> GaryG wrote:
>> 
>> Thank you for pointing that out!  Since we only have one broker, I
>> disabled the multicast discovery.  
>> 
>> Unfortunately, that didn't fix the problem.  The restarts are still
>> happening.  Sometimes they occur within few minutes of startup, sometimes
>> takes 4-5 minutes.  The only relevant info I see in "activemq.log" is
>> this:
>> 
>> 2009-07-30 17:42:54,652 [MQ ShutdownHook] INFO  BrokerService                 
>> - ActiveMQ Message Broker (ai_jms, ID:server2-53314-1248975478282-0:0) is
>> shutting down
>> 2009-07-30 17:42:54,653 [MQ ShutdownHook] DEBUG BrokerService                 
>> - Caught exception, must be shutting down:
>> java.lang.IllegalStateException: Shutdown in progress
>> 2009-07-30 17:42:54,657 [MQ ShutdownHook] INFO  NetworkConnector              
>> - Network Connector local-nc Stopped
>> 2009-07-30 17:42:56,089 [31.140.18:56800]
>> 
>> Which makes me thing that something is sending a kill command to the
>> process, but I have no idea what that could be.
>> 
>> _Gary
>> 
>> 
>> rajdavies wrote:
>>> 
>>> first - try disabling multicast discovery in the activemq configuration
>>> 
>>> On 29 Jul 2009, at 22:17, GaryG wrote:
>>> 
>>>>
>>>> We've recently updated to ActiveMQ 5.2.0, and are running it as a  
>>>> standalone
>>>> server, with a config file very similar to the basic example  
>>>> provided out of
>>>> the box.  There has been no code change in the Java code that talks  
>>>> to the
>>>> AMQ server.  Yet, once started up, the ActiveMQ server process is  
>>>> restarting
>>>> itself every 5 minutes.
>>>>
>>>> Looking at the "activemq.log", I see the following:
>>>> ===============
>>>> .
>>>> .
>>>> .
>>>> 2009-07-29 20:48:01,949 [31.140.17:41258] DEBUG AbstractRegion
>>>> - Adding destination: topic:// 
>>>> ActiveMQ.Advisory.Producer.Topic.dr01b_wf1
>>>> 2009-07-29 20:48:01,951 [31.140.17:41258] DEBUG AbstractRegion
>>>> - Adding destination:
>>>> topic://ActiveMQ.Advisory.Producer.Topic.WorkerFarmControl
>>>> 2009-07-29 20:48:01,952 [31.140.17:41258] DEBUG AbstractRegion
>>>> - Adding destination: topic:// 
>>>> ActiveMQ.Advisory.Producer.Topic.dr01a_wf1
>>>> 2009-07-29 20:48:01,956 [31.140.17:41258] DEBUG AbstractRegion
>>>> - Adding destination: topic://ControllerCCTopicSend
>>>> 2009-07-29 20:48:01,957 [31.140.17:41258] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Waking for checkpoint to complete.
>>>> 2009-07-29 20:48:01,957 [eckpoint Worker] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Checkpoint started.
>>>> 2009-07-29 20:48:01,979 [eckpoint Worker] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Checkpoint done.
>>>> 2009-07-29 20:48:01,984 [31.140.17:41258] DEBUG AbstractRegion
>>>> - Adding destination:
>>>> topic://ActiveMQ.Advisory.Producer.Topic.ControllerCCTopicSend
>>>> 2009-07-29 20:52:55,790 [MQ ShutdownHook] INFO  BrokerService
>>>> - ActiveMQ Message Broker (ai_jms,  
>>>> ID:server2-55452-1248900479410-0:0) is
>>>> shutting down
>>>> 2009-07-29 20:52:55,791 [MQ ShutdownHook] DEBUG BrokerService
>>>> - Caught exception, must be shutting down:  
>>>> java.lang.IllegalStateException:
>>>> Shutdown in progress
>>>> 2009-07-29 20:52:55,796 [MQ ShutdownHook] INFO  NetworkConnector
>>>> - Network Connector local-nc Stopped
>>>> 2009-07-29 20:52:57,294 [31.140.18:56300] DEBUG TransportConnection
>>>> - Stopping connection: /1.1.1.18:56300
>>>> 2009-07-29 20:52:57,294 [31.140.18:56300] DEBUG TcpTransport
>>>> - Stopping transport tcp:///1.1.1.18:56300
>>>> 2009-07-29 20:52:57,297 [31.140.18:56300] DEBUG TransportConnection
>>>> - Stopped transport: /1.1.1.18:56300
>>>> 2009-07-29 20:52:57,298 [31.140.18:56300] DEBUG TransportConnection
>>>> - Cleaning up connection resources: /1.1.1.18:56300
>>>> 2009-07-29 20:52:57,299 [31.140.18:56300] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Waking for checkpoint to complete.
>>>> 2009-07-29 20:52:57,299 [eckpoint Worker] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Checkpoint started.
>>>> 2009-07-29 20:52:57,331 [eckpoint Worker] DEBUG  
>>>> JournalPersistenceAdapter
>>>> - Checkpoint done.
>>>> 2009-07-29 20:52:57,338 [31.140.18:56300] DEBUG AbstractRegion
>>>> - Removing consumer: ID:server2-49559-1248899931358-0:2:-1:1
>>>> .
>>>> .
>>>> .
>>>> -------------
>>>>
>>>> So you can see for a while, the broker's adding topics and such, and  
>>>> then
>>>> all of a sudden it gets an "IllegalStateException", and just restarts.
>>>>
>>>>
>>>> On the clients, when this happens we get this error:
>>>>
>>>> --------------
>>>> 2009-07-29 20:52:48,550 [ActiveMQ Session Task] DEBUG jms_comm -
>>>> ActiveMQMessageReceiver[dr01b_wf1] got msg from = STG_AIC1,
>>>> jmsMsgID=ID:server1-41646-1248899975358-0:2:6:1:224
>>>> 2009-07-29 20:52:48,550 [ActiveMQ Session Task] DEBUG jms_comm -
>>>> ActiveMQMessageReceiver[dr01b_wf1] sent processed msg to  
>>>> messageListener!
>>>> 2009-07-29 20:52:49,896 [ActiveMQ Session Task] DEBUG jms_comm -
>>>> ActiveMQMessageReceiver[dr01b_wf1] got msg from = STG_AIC1,
>>>> jmsMsgID=ID:server1-41646-1248899975358-0:2:6:1:225
>>>> 2009-07-29 20:52:49,896 [ActiveMQ Session Task] DEBUG jms_comm -
>>>> ActiveMQMessageReceiver[dr01b_wf1] sent processed msg to  
>>>> messageListener!
>>>> 2009-07-29 20:52:57,865 [ActiveMQ Connection Worker:
>>>> tcp://server2/1.1.1.18:61616] ERROR jms_comm - FactoryUtil.onException
>>>> javax.jms.JMSException: java.io.EOFException
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:49)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq 
>>>> .ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1773)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1790)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.transport.TransportFilter.onException(TransportFilter.java: 
>>>> 99)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq 
>>>> .transport.ResponseCorrelator.onException(ResponseCorrelator.java:114)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.transport.TransportFilter.onException(TransportFilter.java: 
>>>> 99)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.transport.TransportFilter.onException(TransportFilter.java: 
>>>> 99)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq 
>>>> .transport 
>>>> .WireFormatNegotiator.onException(WireFormatNegotiator.java:152)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq 
>>>> .transport.InactivityMonitor.onException(InactivityMonitor.java:244)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq 
>>>> .transport.TransportSupport.onException(TransportSupport.java:96)
>>>>        at
>>>> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java: 
>>>> 189)
>>>>        at java.lang.Thread.run(Thread.java:619)
>>>> Caused by: java.io.EOFException
>>>>        at java.io.DataInputStream.readInt(DataInputStream.java:375)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269)
>>>>        at
>>>> org 
>>>> .apache 
>>>> .activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java: 
>>>> 210)
>>>>        at
>>>> org 
>>>> .apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java: 
>>>> 202)
>>>>        at
>>>> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java: 
>>>> 185)
>>>>        ... 1 more
>>>> 2009-07-29 20:52:57,895 [ActiveMQ Connection Worker:
>>>> tcp://server2.mss.iss.net/1.1.1.18:61616] DEBUG jms_comm - JMS  
>>>> Exception
>>>> occured. Server is down.
>>>> 2009-07-29 20:52:58,263 [Thread-27] ERROR jms_comm.log -
>>>> ActiveMQMessageSender[ControllerTaskStatusTopic] Error sending  
>>>> message:
>>>> javax.jms.JMSException: Channel was inactive for too long:
>>>> server2/1.1.1.18:61616
>>>> --------------
>>>>
>>>>
>>>> Our "activemq.xml" file is pretty simple - it's almost exactly the  
>>>> default
>>>> config with just some minor modifications:
>>>> ----------------------
>>>>
>>>> <!--
>>>>    Licensed to the Apache Software Foundation (ASF) under one or more
>>>>    contributor license agreements.  See the NOTICE file distributed  
>>>> with
>>>>    this work for additional information regarding copyright ownership.
>>>>    The ASF licenses this file to You under the Apache License,  
>>>> Version 2.0
>>>>    (the "License"); you may not use this file except in compliance  
>>>> with
>>>>    the License.  You may obtain a copy of the License at
>>>>
>>>>    http://www.apache.org/licenses/LICENSE-2.0
>>>>
>>>>    Unless required by applicable law or agreed to in writing, software
>>>>    distributed under the License is distributed on an "AS IS" BASIS,
>>>>    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or  
>>>> implied.
>>>>    See the License for the specific language governing permissions and
>>>>    limitations under the License.
>>>> -->
>>>> <!-- START SNIPPET: example -->
>>>> <beans
>>>>  xmlns="http://www.springframework.org/schema/beans"
>>>>  xmlns:amq="http://activemq.apache.org/schema/core"
>>>>  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
>>>>  xsi:schemaLocation="http://www.springframework.org/schema/beans
>>>> http://www.springframework.org/schema/beans/spring-beans-2.0.xsd
>>>>  http://activemq.apache.org/schema/core
>>>> http://activemq.apache.org/schema/core/activemq-core.xsd
>>>>  http://activemq.apache.org/camel/schema/spring
>>>> http://activemq.apache.org/camel/schema/spring/camel-spring.xsd">
>>>>
>>>>  <!-- Allows us to use system properties as variables in this  
>>>> configuration
>>>> file -->
>>>>  <bean
>>>> class 
>>>> = 
>>>> "org 
>>>> .springframework.beans.factory.config.PropertyPlaceholderConfigurer">
>>>>    <property name="locations">
>>>>      <value>file:///${activemq.base}/conf/credentials.properties</

>>>> value>
>>>>    </property>
>>>>  </bean>
>>>>
>>>>  <broker xmlns="http://activemq.apache.org/schema/core"  
>>>> brokerName="ai_jms"
>>>> useJmx="true" dataDirectory="${activemq.base}/data">
>>>>
>>>>    <!-- The store and forward broker networks ActiveMQ will listen  
>>>> to -->
>>>>    <networkConnectors>
>>>>      <!-- by default just auto discover the other brokers -->
>>>>      <!--<networkConnector name="default-nc" uri="multicast:// 
>>>> default"/>
>>>> -->
>>>>      <!-- Example of a static configuration: -->
>>>>      <networkConnector name="local-nc"
>>>> uri="static://(tcp://localhost:61616)"/>
>>>>    </networkConnectors>
>>>>
>>>>    <persistenceAdapter>
>>>>      <journaledJDBC journalLogFiles="10"
>>>> dataDirectory="${activemq.base}/activemq-data" dataSource="#derby- 
>>>> ds"/>
>>>>    </persistenceAdapter>
>>>>
>>>>
>>>>    <!--  The maximum about of space the broker will use before  
>>>> slowing down
>>>> producers -->
>>>>    <systemUsage>
>>>>      <systemUsage>
>>>>        <memoryUsage>
>>>>          <memoryUsage limit="512 mb"/>
>>>>        </memoryUsage>
>>>>        <storeUsage>
>>>>          <storeUsage limit="1 gb" name="foo"/>
>>>>        </storeUsage>
>>>>        <tempUsage>
>>>>          <tempUsage limit="100 mb"/>
>>>>        </tempUsage>
>>>>      </systemUsage>
>>>>    </systemUsage>
>>>>
>>>>    <!-- The transport connectors ActiveMQ will listen to -->
>>>>    <transportConnectors>
>>>>      <transportConnector name="openwire" uri="tcp://localhost:61616"
>>>> discoveryUri="multicast://default"/>
>>>>    </transportConnectors>
>>>>
>>>>  </broker>
>>>>
>>>>  <!-- An embedded servlet engine for serving up the Admin console -->
>>>>  <jetty xmlns="http://mortbay.com/schemas/jetty/1.0">
>>>>    <connectors>
>>>>      <nioConnector port="8161"/>
>>>>    </connectors>
>>>>
>>>>    <handlers>
>>>>      <webAppContext contextPath="/admin"
>>>> resourceBase="${activemq.base}/webapps/admin" logUrlOnStart="true"/>
>>>>      <webAppContext contextPath="/demo"
>>>> resourceBase="${activemq.base}/webapps/demo" logUrlOnStart="true"/>
>>>>      <webAppContext contextPath="/fileserver"
>>>> resourceBase="${activemq.base}/webapps/fileserver"  
>>>> logUrlOnStart="true"/>
>>>>    </handlers>
>>>>  </jetty>
>>>>
>>>>  <!-- Embedded Derby DataSource Sample Setup -->
>>>>  <bean id="derby-ds" class="org.apache.derby.jdbc.EmbeddedDataSource">
>>>>    <property name="databaseName" value="derbydb"/>
>>>>    <property name="createDatabase" value="create"/>
>>>>  </bean>
>>>>
>>>> </beans>
>>>>  <!-- END SNIPPET: example -->
>>>>
>>>>
>>>>
>>>> ----------------------
>>>>
>>>>
>>>> And our Java clients use the following URL to connect to the server:
>>>>
>>>> tcp://${jms.server}:${jms.port}? 
>>>> keepAlive 
>>>> = 
>>>> true 
>>>> &amp 
>>>> ;connectionTimeout 
>>>> = 
>>>> 0 
>>>> &amp 
>>>> ;wireFormat 
>>>> .maxInactivityDuration 
>>>> =0&amp;jms.useAsyncSend=true&amp;jms.prefetchPolicy.all=250"
>>>>
>>>>
>>>> Notice that I tried setting the connectionTimeout and  
>>>> maxInactivityDuration
>>>> to "0" thinking that this would turn off inactivity checking.
>>>> This didn't help.  Further, the system does try to send through a  
>>>> LOT of
>>>> traffic when we bring it up, so there's definitely no "inactivity".
>>>>
>>>> As I mentioned, the exact same codebase was working perfectly fine  
>>>> with
>>>> ActiveMQ 4.1.1.  There's been no code changes, and no changes in the  
>>>> nature
>>>> of the logs we're sending through.  The only change has been  
>>>> upgrading to
>>>> AMQ 5.2.0 on the server side, and using the new jar file on the
>>>> Java client side.
>>>>
>>>> Any help would be appreciated, as I'm totally stumped as to why the  
>>>> server
>>>> keeps restarting itself.  Our message content hasn't changed,
>>>> so why would the EOF file errors or "channel inactive" errors be  
>>>> happening??
>>>>
>>>> Thanks,
>>>> Gary
>>>>
>>>> -- 
>>>> View this message in context:
>>>> http://www.nabble.com/Standalone-server-restarting-itself-every-5-minutes---java.lang.IllegalStateException-tp24727769p24727769.html
>>>> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>>>>
>>> 
>>> Rob Davies
>>> I work here: http://fusesource.com
>>> My Blog: http://rajdavies.blogspot.com/
>>> I'm writing this: http://www.manning.com/snyder/
>>> 
>>> 
>>> 
>>> 
>>> 
>>> 
>> 
>> 
> 
> 

-- 
View this message in context: http://www.nabble.com/Standalone-server-restarting-itself-every-5-minutes---java.lang.IllegalStateException-tp24727769p24746414.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Mime
View raw message