[JAMES-991] IllegalStateException during shutdown

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: Trunk
• Fix Version/s: 3.0-M1
• Component/s: James Core
• Environment: WinXP
• Assignee: Norman Maurer
• Reporter: Tim-Christian Mundt
• Created: 23/Apr/10 09:32
• Updated: 04/Jul/10 11:17
• Resolved: 04/Jul/10 11:17

Description

Sometimes (I love undetermined errors...) when shutting down James (current rev 936628) the CPU load goes very high and the system (Win XP) becomes totally unresponsive (although James only takes around 50% of the CPU (dual core)). I get this output:

INFO 11:07:21,203 | org.apache.activemq.broker.BrokerService | ActiveMQ Message Broker (localhost, ID:timpad-1542-1272013579921-0:0) is shutting down
INFO 11:07:21,203 | org.apache.james.container.spring.JamesServerApplicationContext | Closing org.apache.james.container.spring.JamesServer
ApplicationContext@12498b5: startup date [Fri Apr 23 11:06:13 CEST 2010]; root of context hierarchy
INFO 11:07:21,218 | james.imapserver | Dispose IMAP Service
INFO 11:07:22,421 | org.apache.activemq.broker.TransportConnector | Connector openwire Stopped
INFO 11:07:22,453 | org.apache.activemq.broker.TransportConnector | Connector vm://localhost Stopped
INFO 11:07:23,921 | org.apache.activemq.broker.BrokerService | ActiveMQ JMS Message Broker (localhost, ID:timpad-1542-1272013579921-0:0) stopped
INFO 11:07:24,781 | org.apache.activemq.broker.BrokerService | Using Persistence Adapter: AMQPersistenceAdapter(activemq-data\localhost)
INFO 11:07:24,796 | org.apache.activemq.store.amq.AMQPersistenceAdapter | AMQStore starting using directory: activemq-data\localhost
INFO 11:07:32,812 | org.apache.activemq.kaha.impl.KahaStore | Kaha Store using data directory activemq-data\localhost\kr-store\state
INFO 11:08:54,515 | org.apache.activemq.store.amq.AMQPersistenceAdapter | Active data files: []

And after a while this error follows:

ERROR 11:09:15,140 | org.apache.activemq.broker.BrokerService | Failed to start ActiveMQ JMS Message Broker. Reason: java.lang.IllegalStateE
xception: Shutdown in progress
java.lang.IllegalStateException: Shutdown in progress
at java.lang.ApplicationShutdownHooks.add(Unknown Source)
at java.lang.Runtime.addShutdownHook(Unknown Source)
at org.apache.activemq.broker.BrokerService.addShutdownHook(BrokerService.java:1844)
at org.apache.activemq.broker.BrokerService.start(BrokerService.java:468)
at org.apache.activemq.transport.vm.VMTransportFactory.doCompositeConnect(VMTransportFactory.java:123)
at org.apache.activemq.transport.vm.VMTransportFactory.doConnect(VMTransportFactory.java:53)
at org.apache.activemq.transport.TransportFactory.doConnect(TransportFactory.java:51)
at org.apache.activemq.transport.TransportFactory.connect(TransportFactory.java:80)
at org.apache.activemq.ActiveMQConnectionFactory.createTransport(ActiveMQConnectionFactory.java:243)
at org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnection(ActiveMQConnectionFactory.java:258)
at org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnection(ActiveMQConnectionFactory.java:230)
at org.apache.activemq.ActiveMQConnectionFactory.createConnection(ActiveMQConnectionFactory.java:178)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:125)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:110)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:81)
at org.springframework.jms.support.JmsAccessor.createConnection(JmsAccessor.java:184)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:456)
at org.springframework.jms.core.JmsTemplate.receiveSelected(JmsTemplate.java:703)
at org.springframework.jms.core.JmsTemplate.receive(JmsTemplate.java:681)
at org.springframework.jms.core.JmsTemplate.receive(JmsTemplate.java:672)
at org.apache.camel.component.jms.JmsPollingConsumer.receive(JmsPollingConsumer.java:71)
at org.apache.camel.component.jms.JmsPollingConsumer.receiveNoWait(JmsPollingConsumer.java:53)
at org.apache.james.transport.camel.JMSSelectorPollingConsumer.poll(JMSSelectorPollingConsumer.java:76)
at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:106)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown Source)
at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
INFO 11:09:19,312 | org.apache.activemq.broker.BrokerService | ActiveMQ Message Broker (localhost, null) is shutting down

I just tried again and after this stacktrace above I get this one:

INFO 11:19:42,328 | org.apache.activemq.broker.BrokerService | ActiveMQ JMS Message Broker (localhost, null) stopped
WARN 11:19:42,343 | org.apache.camel.impl.DefaultPollingConsumerPollStrategy | Consumer Consumer[pollingjms://queue?consumer.endpointUri=activemq%3Aqueue%3Aoutgoing.retry&delay=30000] could not poll endpoint: pollingjms://queue?consumer.endpointUri=activemq%3Aqueue%3Aoutgoing.retry&delay=30000 caused by: Uncategorized exception occured during JMS processing; nested exception is javax.jms.JMSException: Could not create Transport. Reason: java.lang.IllegalStateException: Shutdown in progress
org.springframework.jms.UncategorizedJmsException: Uncategorized exception occured during JMS processing; nested exception is javax.jms.JMSException: Could not create Transport. Reason: java.lang.IllegalStateException: Shutdown in progress
at org.springframework.jms.support.JmsUtils.convertJmsAccessException(JmsUtils.java:316)
at org.springframework.jms.support.JmsAccessor.convertJmsAccessException(JmsAccessor.java:168)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:469)
at org.springframework.jms.core.JmsTemplate.receiveSelected(JmsTemplate.java:703)
at org.springframework.jms.core.JmsTemplate.receive(JmsTemplate.java:681)
at org.springframework.jms.core.JmsTemplate.receive(JmsTemplate.java:672)
at org.apache.camel.component.jms.JmsPollingConsumer.receive(JmsPollingConsumer.java:71)
at org.apache.camel.component.jms.JmsPollingConsumer.receiveNoWait(JmsPollingConsumer.java:53)
at org.apache.james.transport.camel.JMSSelectorPollingConsumer.poll(JMSSelectorPollingConsumer.java:76)
at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:106)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown Source)
at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: javax.jms.JMSException: Could not create Transport. Reason: java.lang.IllegalStateException: Shutdown in progress
at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:35)
at org.apache.activemq.ActiveMQConnectionFactory.createTransport(ActiveMQConnectionFactory.java:245)
at org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnection(ActiveMQConnectionFactory.java:258)
at org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnection(ActiveMQConnectionFactory.java:230)
at org.apache.activemq.ActiveMQConnectionFactory.createConnection(ActiveMQConnectionFactory.java:178)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:125)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:110)
at org.apache.activemq.pool.PooledConnectionFactory.createConnection(PooledConnectionFactory.java:81)
at org.springframework.jms.support.JmsAccessor.createConnection(JmsAccessor.java:184)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:456)
... 16 more
Caused by: java.lang.IllegalStateException: Shutdown in progress
at java.lang.ApplicationShutdownHooks.add(Unknown Source)
at java.lang.Runtime.addShutdownHook(Unknown Source)
at org.apache.activemq.broker.BrokerService.addShutdownHook(BrokerService.java:1844)
at org.apache.activemq.broker.BrokerService.start(BrokerService.java:468)
at org.apache.activemq.transport.vm.VMTransportFactory.doCompositeConnect(VMTransportFactory.java:123)
at org.apache.activemq.transport.vm.VMTransportFactory.doConnect(VMTransportFactory.java:53)
at org.apache.activemq.transport.TransportFactory.doConnect(TransportFactory.java:51)
at org.apache.activemq.transport.TransportFactory.connect(TransportFactory.java:80)
at org.apache.activemq.ActiveMQConnectionFactory.createTransport(ActiveMQConnectionFactory.java:243)
... 24 more
INFO 11:20:13,312 | org.apache.activemq.broker.BrokerService | Using Persistence Adapter: AMQPersistenceAdapter(activemq-data\localhost)
INFO 11:20:13,312 | org.apache.activemq.store.amq.AMQPersistenceAdapter | AMQStore starting using directory: activemq-data\localhost
INFO 11:20:13,328 | org.apache.activemq.kaha.impl.KahaStore | Kaha Store using data directory activemq-data\localhost\kr-store\state
INFO 11:20:13,359 | org.apache.activemq.store.amq.AMQPersistenceAdapter | Active data files: []

Both these errors alternate with some pause in between until I kill the process. CPU-load is high all the time.