Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

GaryG
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:
----------------------



<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">

 
  <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">

   
    <networkConnectors>
     
     
     
      <networkConnector name="local-nc" uri="static://(tcp://localhost:61616)"/>
    </networkConnectors>

    <persistenceAdapter>
      <journaledJDBC journalLogFiles="10" dataDirectory="${activemq.base}/activemq-data" dataSource="#derby-ds"/>
    </persistenceAdapter>


   
    <systemUsage>
      <systemUsage>
        <memoryUsage>
          <memoryUsage limit="512 mb"/>
        </memoryUsage>
        <storeUsage>
          <storeUsage limit="1 gb" name="foo"/>
        </storeUsage>
        <tempUsage>
          <tempUsage limit="100 mb"/>
        </tempUsage>
      </systemUsage>
    </systemUsage>

   
    <transportConnectors>
      <transportConnector name="openwire" uri="tcp://localhost:61616" discoveryUri="multicast://default"/>
    </transportConnectors>

  </broker>

 
  <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>

 
  <bean id="derby-ds" class="org.apache.derby.jdbc.EmbeddedDataSource">
    <property name="databaseName" value="derbydb"/>
    <property name="createDatabase" value="create"/>
  </bean>

</beans>
 



----------------------


And our Java clients use the following URL to connect to the server:

tcp://${jms.server}:${jms.port}?keepAlive=true&connectionTimeout=0&wireFormat.maxInactivityDuration=0&jms.useAsyncSend=true&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
Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

rajdavies
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/




Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

GaryG
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:
> ----------------------
>
>
>
> <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">
>
>  
>  <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">
>
>    
>    <networkConnectors>
>      
>      
>      
>      <networkConnector name="local-nc"
> uri="static://(tcp://localhost:61616)"/>
>    </networkConnectors>
>
>    <persistenceAdapter>
>      <journaledJDBC journalLogFiles="10"
> dataDirectory="${activemq.base}/activemq-data" dataSource="#derby-
> ds"/>
>    </persistenceAdapter>
>
>
>    
>    <systemUsage>
>      <systemUsage>
>        <memoryUsage>
>          <memoryUsage limit="512 mb"/>
>        </memoryUsage>
>        <storeUsage>
>          <storeUsage limit="1 gb" name="foo"/>
>        </storeUsage>
>        <tempUsage>
>          <tempUsage limit="100 mb"/>
>        </tempUsage>
>      </systemUsage>
>    </systemUsage>
>
>    
>    <transportConnectors>
>      <transportConnector name="openwire" uri="tcp://localhost:61616"
> discoveryUri="multicast://default"/>
>    </transportConnectors>
>
>  </broker>
>
>  
>  <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>
>
>  
>  <bean id="derby-ds" class="org.apache.derby.jdbc.EmbeddedDataSource">
>    <property name="databaseName" value="derbydb"/>
>    <property name="createDatabase" value="create"/>
>  </bean>
>
> </beans>
>  
>
>
>
> ----------------------
>
>
> And our Java clients use the following URL to connect to the server:
>
> tcp://${jms.server}:${jms.port}?
> keepAlive
> =
> true
> &
> ;connectionTimeout
> =
> 0
> &
> ;wireFormat
> .maxInactivityDuration
> =0&jms.useAsyncSend=true&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/



Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

GaryG
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:
> ----------------------
>
>
>
> <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">
>
>  
>  <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">
>
>    
>    <networkConnectors>
>      
>      
>      
>      <networkConnector name="local-nc"
> uri="static://(tcp://localhost:61616)"/>
>    </networkConnectors>
>
>    <persistenceAdapter>
>      <journaledJDBC journalLogFiles="10"
> dataDirectory="${activemq.base}/activemq-data" dataSource="#derby-
> ds"/>
>    </persistenceAdapter>
>
>
>    
>    <systemUsage>
>      <systemUsage>
>        <memoryUsage>
>          <memoryUsage limit="512 mb"/>
>        </memoryUsage>
>        <storeUsage>
>          <storeUsage limit="1 gb" name="foo"/>
>        </storeUsage>
>        <tempUsage>
>          <tempUsage limit="100 mb"/>
>        </tempUsage>
>      </systemUsage>
>    </systemUsage>
>
>    
>    <transportConnectors>
>      <transportConnector name="openwire" uri="tcp://localhost:61616"
> discoveryUri="multicast://default"/>
>    </transportConnectors>
>
>  </broker>
>
>  
>  <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>
>
>  
>  <bean id="derby-ds" class="org.apache.derby.jdbc.EmbeddedDataSource">
>    <property name="databaseName" value="derbydb"/>
>    <property name="createDatabase" value="create"/>
>  </bean>
>
> </beans>
>  
>
>
>
> ----------------------
>
>
> And our Java clients use the following URL to connect to the server:
>
> tcp://${jms.server}:${jms.port}?
> keepAlive
> =
> true
> &
> ;connectionTimeout
> =
> 0
> &
> ;wireFormat
> .maxInactivityDuration
> =0&jms.useAsyncSend=true&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/



Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

GaryG
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:
> ----------------------
>
>
>
> <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">
>
>  
>  <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">
>
>    
>    <networkConnectors>
>      
>      
>      
>      <networkConnector name="local-nc"
> uri="static://(tcp://localhost:61616)"/>
>    </networkConnectors>
>
>    <persistenceAdapter>
>      <journaledJDBC journalLogFiles="10"
> dataDirectory="${activemq.base}/activemq-data" dataSource="#derby-
> ds"/>
>    </persistenceAdapter>
>
>
>    
>    <systemUsage>
>      <systemUsage>
>        <memoryUsage>
>          <memoryUsage limit="512 mb"/>
>        </memoryUsage>
>        <storeUsage>
>          <storeUsage limit="1 gb" name="foo"/>
>        </storeUsage>
>        <tempUsage>
>          <tempUsage limit="100 mb"/>
>        </tempUsage>
>      </systemUsage>
>    </systemUsage>
>
>    
>    <transportConnectors>
>      <transportConnector name="openwire" uri="tcp://localhost:61616"
> discoveryUri="multicast://default"/>
>    </transportConnectors>
>
>  </broker>
>
>  
>  <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>
>
>  
>  <bean id="derby-ds" class="org.apache.derby.jdbc.EmbeddedDataSource">
>    <property name="databaseName" value="derbydb"/>
>    <property name="createDatabase" value="create"/>
>  </bean>
>
> </beans>
>  
>
>
>
> ----------------------
>
>
> And our Java clients use the following URL to connect to the server:
>
> tcp://${jms.server}:${jms.port}?
> keepAlive
> =
> true
> &
> ;connectionTimeout
> =
> 0
> &
> ;wireFormat
> .maxInactivityDuration
> =0&jms.useAsyncSend=true&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/



Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

rajdavies
In reply to this post by GaryG
ooh - sounds like you have more than one broker running in your  
environment - something is creating a network connection to your broker

On 30 Jul 2009, at 18:58, 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-tp24727769p24743651.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/




Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

GaryG
Actually, no we didn't - I just meant that I tried two different versions of the broker to try and figure out what the problem was.

We actually found the problem - turned out that I was reading the logs correctly - there was a kill signal being send to the ActiveMQ process - IT had a monitoring tool running on the box, looking for activemq, and was incorrectly parsing the process name, so after it thought activemq wasn't running, it was attempting to restart it.  

rajdavies wrote
ooh - sounds like you have more than one broker running in your  
environment - something is creating a network connection to your broker

On 30 Jul 2009, at 18:58, 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:
>>> ----------------------
>>>
>>>
>>>
>>> <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">
>>>
>>>
>>> <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">
>>>
>>>  
>>>   <networkConnectors>
>>>    
>>>    
>>>    
>>>     <networkConnector name="local-nc"
>>> uri="static://(tcp://localhost:61616)"/>
>>>   </networkConnectors>
>>>
>>>   <persistenceAdapter>
>>>     <journaledJDBC journalLogFiles="10"
>>> dataDirectory="${activemq.base}/activemq-data" dataSource="#derby-
>>> ds"/>
>>>   </persistenceAdapter>
>>>
>>>
>>>  
>>>   <systemUsage>
>>>     <systemUsage>
>>>       <memoryUsage>
>>>         <memoryUsage limit="512 mb"/>
>>>       </memoryUsage>
>>>       <storeUsage>
>>>         <storeUsage limit="1 gb" name="foo"/>
>>>       </storeUsage>
>>>       <tempUsage>
>>>         <tempUsage limit="100 mb"/>
>>>       </tempUsage>
>>>     </systemUsage>
>>>   </systemUsage>
>>>
>>>  
>>>   <transportConnectors>
>>>     <transportConnector name="openwire" uri="tcp://localhost:61616"
>>> discoveryUri="multicast://default"/>
>>>   </transportConnectors>
>>>
>>> </broker>
>>>
>>>
>>> <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>
>>>
>>>
>>> <bean id="derby-ds"  
>>> class="org.apache.derby.jdbc.EmbeddedDataSource">
>>>   <property name="databaseName" value="derbydb"/>
>>>   <property name="createDatabase" value="create"/>
>>> </bean>
>>>
>>> </beans>
>>>
>>>
>>>
>>>
>>> ----------------------
>>>
>>>
>>> And our Java clients use the following URL to connect to the server:
>>>
>>> tcp://${jms.server}:${jms.port}?
>>> keepAlive
>>> =
>>> true
>>> &
>>> ;connectionTimeout
>>> =
>>> 0
>>> &
>>> ;wireFormat
>>> .maxInactivityDuration
>>> =0&jms.useAsyncSend=true&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-tp24727769p24743651.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/



Reply | Threaded
Open this post in threaded view
|

Re: Standalone server restarting itself every 5 minutes - java.lang.IllegalStateException

rajdavies
ah - thanks for letting us know!

cheers,

Rob
On 31 Jul 2009, at 15:30, GaryG wrote:

>
> Actually, no we didn't - I just meant that I tried two different  
> versions of
> the broker to try and figure out what the problem was.
>
> We actually found the problem - turned out that I was reading the logs
> correctly - there was a kill signal being send to the ActiveMQ  
> process - IT
> had a monitoring tool running on the box, looking for activemq, and  
> was
> incorrectly parsing the process name, so after it thought activemq  
> wasn't
> running, it was attempting to restart it.
>
>
> rajdavies wrote:
>>
>> ooh - sounds like you have more than one broker running in your
>> environment - something is creating a network connection to your  
>> broker
>>
>> On 30 Jul 2009, at 18:58, 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-tp24727769p24743651.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-tp24727769p24757412.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/