OutOfMemoryError after 9505925 persistent messages
--------------------------------------------------
Key: AMQ-2090
URL: https://issues.apache.org/activemq/browse/AMQ-2090
Project: ActiveMQ
Issue Type: Bug
Components: Message Store
Affects Versions: 5.2.0
Environment: Debian 64 bit, 8 GB mem, jdk1.6.0_10,
apache-activemq-5.2.0.1-fuse
Reporter: Jörg Zintel
Priority: Critical
When I was doing a high load 24/7 test where I produced 9505925 persistent
small message (kaha) suddenly amq stopped working with an OutOfMemoryException.
My memory settings are
-Xmn100M \
-Xms500M \
-Xmx1024M
The Exception looks like this:
Exception in thread "ActiveMQ Connection Dispatcher: /127.0.0.1:32929"
java.lang.OutOfMemoryError: Java heap space
at java.util.jar.Attributes.read(Attributes.java:377)
at java.util.jar.Manifest.read(Manifest.java:182)
at java.util.jar.Manifest.<init>(Manifest.java:52)
at java.util.jar.JarFile.getManifestFromReference(JarFile.java:165)
at java.util.jar.JarFile.getManifest(JarFile.java:146)
at sun.misc.URLClassPath$JarLoader$2.getManifest(URLClassPath.java:693)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:221)
at java.net.URLClassLoader.access$000(URLClassLoader.java:56)
at java.net.URLClassLoader$1.run(URLClassLoader.java:195)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
at
org.apache.activemq.broker.TransportConnection.serviceExceptionAsync(TransportConnection.java:244)
at
org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:841)
at
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
at
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
Exception in thread "ActiveMQ Scheduler" java.lang.OutOfMemoryError: Java heap
space
at java.util.HashMap.addEntry(HashMap.java:753)
at java.util.HashMap.put(HashMap.java:385)
at java.util.HashSet.add(HashSet.java:200)
at java.util.AbstractCollection.addAll(AbstractCollection.java:305)
at
org.apache.activemq.store.amq.AMQPersistenceAdapter.cleanup(AMQPersistenceAdapter.java:439)
at
org.apache.activemq.store.amq.AMQPersistenceAdapter$3.run(AMQPersistenceAdapter.java:279)
at
org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
at java.io.BufferedInputStream.<init>(BufferedInputStream.java:178)
at java.io.BufferedInputStream.<init>(BufferedInputStream.java:158)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:679)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
Exception in thread "RMI TCP Connection(idle)" at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
java.lang.OutOfMemoryError: Java heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "InactivityMonitor WriteCheck" java.lang.OutOfMemoryError:
Java heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: Java
heap space
...
The stdout looks like this:
2009-01-28 10:48:35,664 [ueue://tracking] DEBUG vemq.store.amq.AMQMessageStore
- Batch update done.
2009-01-28 10:48:33,537 [iveMQ Scheduler] DEBUG tore.amq.AMQPersistenceAdapter
- lastDataFile: 5663
2009-01-28 10:48:27,177 [itor WriteCheck] DEBUG .transport.InactivityMonitor$2
- 72107 ms elapsed since last write check.
2009-01-28 10:48:56,877 [iveMQ Scheduler] DEBUG ha.impl.async.AsyncDataManager
- lastFileId=5662, purgeList: (0) []
2009-01-28 10:48:52,634 [ueue://tracking] DEBUG vemq.store.amq.AMQMessageStore
- Doing batch update... adding: 3 removing: 4
2009-01-28 10:48:48,395 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3395:1:2,
at: offset = 168080, file = 5663, size = 384, type = 1
2009-01-28 10:48:48,395 [127.0.0.1:32929] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message remove for: ID:adbl006-40098-1233049753494-0:30:278402
8:1:1, at: offset = 167801, file = 5663, size = 279, type = 1
2009-01-28 10:48:37,784 [nitor ReadCheck] DEBUG .transport.InactivityMonitor$1
- 27573 ms elapsed since last read check.
2009-01-28 10:51:32,122 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3392:1:2,
at: offset = 168464, file = 5663, size = 384, type = 1
2009-01-28 10:51:27,528 [ueue://tracking] DEBUG vemq.store.amq.AMQMessageStore
- Batch update done.
2009-01-28 10:50:48,614 [itor WriteCheck] DEBUG .transport.InactivityMonitor$2
- 165814 ms elapsed since last write check.
2009-01-28 10:50:48,614 [iveMQ Scheduler] DEBUG tore.amq.AMQPersistenceAdapter
- dataFilesInProgress.values: (1) [{5663=3}]
2009-01-28 10:51:40,604 [ueue://tracking] DEBUG vemq.store.amq.AMQMessageStore
- Doing batch update... adding: 2 removing: 1
2009-01-28 10:51:36,365 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3391:1:2,
at: offset = 169127, file = 5663, size = 384, type = 1
2009-01-28 10:51:32,122 [127.0.0.1:32929] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message remove for: ID:adbl006-40098-1233049753494-0:30:278403
2:1:1, at: offset = 168848, file = 5663, size = 279, type = 1
2009-01-28 10:51:32,122 [nitor ReadCheck] DEBUG .transport.InactivityMonitor$1
- 197674 ms elapsed since last read check.
2009-01-28 10:55:28,803 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3385:1:2,
at: offset = 169511, file = 5663, size = 384, type = 1
2009-01-28 10:55:28,803 [ueue://tracking] DEBUG vemq.store.amq.AMQMessageStore
- Batch update done.
2009-01-28 11:09:10,234 [.21.150.21:8161] ERROR rg.slf4j.impl.JCLLoggerAdapter
- EXCEPTION
java.lang.OutOfMemoryError: Java heap space
2009-01-28 10:58:33,322 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3383:1:2,
at: offset = 170174, file = 5663, size = 384, type = 1
2009-01-28 10:55:51,594 [127.0.0.1:32929] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message remove for: ID:adbl006-40098-1233049753494-0:30:278372
5:1:7, at: offset = 169895, file = 5663, size = 279, type = 1
2009-01-28 10:55:42,624 [nitor ReadCheck] DEBUG .transport.InactivityMonitor$1
- 424840 ms elapsed since last read check.
2009-01-28 11:17:46,299 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:2915:1:4,
at: offset = 170558, file = 5663, size = 384, type = 1
2009-01-28 11:17:03,736 [127.0.0.1:32929] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message remove for: ID:adbl006-40098-1233049753494-0:30:278403
3:1:1, at: offset = 170942, file = 5663, size = 279, type = 1
2009-01-28 11:13:41,738 [3895...@qtp0-14] ERROR rg.slf4j.impl.JCLLoggerAdapter
- /admin/queues.jsp
java.lang.OutOfMemoryError: Java heap space
2009-01-28 11:09:25,197 [Timer-0 ] ERROR rg.slf4j.impl.JCLLoggerAdapter
- Problem scavenging sessions
java.lang.OutOfMemoryError: Java heap space
2009-01-28 11:19:30,007 [127.0.0.1:32929] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message remove for: ID:adbl006-40098-1233049753494-0:30:278403
5:1:1, at: offset = 171605, file = 5663, size = 279, type = 1
2009-01-28 11:18:50,504 [127.0.0.1:39844] DEBUG vemq.store.amq.AMQMessageStore
- Journalled message add for: ID:adbl006-40098-1233049753494-0:38:3328:1:3,
at: offset = 171221, file = 5663, size = 384, type = 1
2009-01-28 11:17:46,299 [nitor ReadCheck] DEBUG .transport.InactivityMonitor$1
- 1574177 ms elapsed since last read check.
2009-01-28 11:30:42,525 [127.0.0.1:32929] DEBUG emq.broker.TransportConnection
- Transport failed: java.io.IOException: Unexpected error occured
java.io.IOException: Unexpected error occured
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:192)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.OutOfMemoryError: Java heap space
2009-01-28 11:31:20,726 [127.0.0.1:39844] DEBUG emq.broker.TransportConnection
- Transport failed: java.io.IOException: Unexpected error occured
java.io.IOException: Unexpected error occured
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:192)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.OutOfMemoryError: Java heap space
2009-01-28 11:39:58,676 [127.0.0.1:39844] DEBUG emq.broker.TransportConnection
- Stopping connection: /127.0.0.1:39844
2009-01-28 11:40:07,371 [127.0.0.1:32929] DEBUG emq.broker.TransportConnection
- Stopping connection: /127.0.0.1:32929
2009-01-28 11:41:04,406 [127.0.0.1:39844] DEBUG emq.transport.tcp.TcpTransport
- Stopping transport tcp:///127.0.0.1:39844
2009-01-28 11:41:26,226 [127.0.0.1:32929] DEBUG emq.transport.tcp.TcpTransport
- Stopping transport tcp:///127.0.0.1:32929
2009-01-28 11:43:11,185 [127.0.0.1:39844] DEBUG emq.broker.TransportConnection
- Stopped transport: /127.0.0.1:39844
2009-01-28 11:47:36,654 [127.0.0.1:32929] DEBUG emq.broker.TransportConnection
- Stopped transport: /127.0.0.1:32929
2009-01-28 11:52:06,738 [127.0.0.1:32929] DEBUG emq.broker.TransportConnection
- Cleaning up connection resources: /127.0.0.1:32929
2009-01-28 11:53:30,458 [127.0.0.1:32929] DEBUG q.broker.region.AbstractRegion
- Removing consumer: ID:adbl006-40098-1233049753494-0:0:-1:1
2009-01-28 11:55:40,444 [127.0.0.1:32929] DEBUG q.broker.region.AbstractRegion
- Removing consumer: ID:adbl006-40098-1233049753494-0:0:1:1
2009-01-28 11:51:49,128 [127.0.0.1:39844] DEBUG emq.broker.TransportConnection
- Cleaning up connection resources: /127.0.0.1:39844
2009-01-28 11:56:07,668 [127.0.0.1:32929] WARN emq.broker.TransportConnection
- Failed to remove consumer: ID:adbl006-40098-1233049753494-0:0:1:1. Reason
: java.lang.OutOfMemoryError: Java heap space
java.lang.OutOfMemoryError: Java heap space
2009-01-28 11:56:23,041 [127.0.0.1:32929] DEBUG emq.broker.TransportConnection
- Connection Stopped: /127.0.0.1:32929
2009-01-28 11:56:23,040 [127.0.0.1:39844] DEBUG q.broker.region.AbstractRegion
- Removing consumer: ID:adbl006-40098-1233049753494-0:38:-1:1
2009-01-28 11:56:46,289 [127.0.0.1:39844] DEBUG emq.broker.TransportConnection
- Connection Stopped: /127.0.0.1:39844
activemq.xml looks like:
<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"/>
<bean id="store"
class="org.apache.activemq.store.amq.AMQPersistenceAdapter">
<property name="directory" value="${activemq.base}/data"/>
<!-- 1GB = 1073741824 -->
<!-- 1MB = 1048576 -->
<property name="maxFileLength" value="1048576"/>
<property name="maxReferenceFileLength" value="1048576"/>
<property name="checkpointInterval" value="60000"/>
<property name="cleanupInterval" value="30000"/>
<property name="persistentIndex" value="true"/>
<property name="indexMaxBinSize" value="10485760"/>
<property name="indexBinSize" value="1048576"/>
<property name="indexPageSize" value="65536"/>
</bean>
<broker xmlns="http://activemq.apache.org/schema/core";
persistent="true"
advisorySupport="false"
deleteAllMessagesOnStartup="true"
useJmx="true"
monitorConnectionSplits="false"
splitSystemUsageForProducersConsumers="false"
brokerName="localhost"
dataDirectory="${activemq.base}/data"
persistenceAdapter="#store"
>
<!-- The maximum about of space the broker will use before slowing
down producers -->
<systemUsage>
<systemUsage sendFailIfNoSpace="true">
<memoryUsage>
<memoryUsage limit="1gb"/>
</memoryUsage>
<storeUsage>
<storeUsage limit="1gb" store="#store"/>
</storeUsage>
<!-- temp usage is used with non persistent messages only -->
<tempUsage>
<tempUsage limit="64mb"/>
</tempUsage>
</systemUsage>
<!-- Use the following to configure how ActiveMQ is exposed in JMX -->
<managementContext>
<managementContext createConnector="true"/>
</managementContext>
<!-- The transport connectors ActiveMQ will listen to -->
<transportConnectors>
<transportConnector name="openwire" uri="tcp://localhost:61616" />
</transportConnectors>
</broker>
<!-- An embedded servlet engine for serving up the Admin console -->
<jetty xmlns="http://mortbay.com/schemas/jetty/1.0";>
<connectors>
<nioConnector host="172.21.150.21" port="8161"/>
</connectors>
<handlers>
<webAppContext contextPath="/admin"
resourceBase="${activemq.home}/webapps/admin" logUrlOnStart="true"/>
</handlers>
</jetty>
</beans>
Other JMS related settings where (spring):
cookie.logic.jms.consumers.min=1
cookie.logic.jms.consumers.max=1
cookie.logic.jms.ActiveMQPrefetchPolicy.prefetchPolicy.queuePrefetch=100
cookie.logic.jms.activemq.broker=tcp://127.0.0.1:61616
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.useAsyncSend=true
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.alwaysSessionAsync=true
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.dispatchAsync=true
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.optimizeAcknowledge=false
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.copyMessageOnSend=false
cookie.logic.jms.ActiveMQConnectionFactory.jmsFactoryAMQ.disableTimeStampsByDefault=true
cookie.logic.jms.PooledConnectionFactory.pooledJmsFactory.maxConnections=1
cookie.logic.jms.JmsTemplate.jmsTemplate.messageIdEnabled=false
cookie.logic.jms.JmsTemplate.jmsTemplate.messageTimestampEnabled=false
cookie.logic.jms.JmsTemplate.jmsTemplate.pubSubNoLocal=false
cookie.logic.jms.JmsTemplate.jmsTemplate.receiveTimeout=-1
# next line has to be set to true if we want to specify non persistent messages
cookie.logic.jms.JmsTemplate.jmsTemplate.explicitQosEnabled=true
cookie.logic.jms.JmsTemplate.jmsTemplate.deliveryMode=javax.jms.DeliveryMode.PERSISTENT
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
