java.lang.OutOfMemoryError: Requested array size exceeds VM
paul.robinson May 9, 2006 5:49 AMHello,
I have installed JBossTS 4.2 into jboss-4.0.3SP1 using the instructions in the INSTALL file that comes with JBossTS. When I boot up the server in all configuration, I receive out of memmory exceptions:
java.lang.OutOfMemoryError: Requested array size exceeds VM limit
There are several of these exceptions which are interlaced with the output from registering the A, B, C and D queues with JNDI.
The output is shown bellow.
Any help would be much apreciated,
Paul.
$ ./run.sh -c all
=========================================================================
JBoss Bootstrap Environment
JBOSS_HOME: d:\java\JBossTS-JBoss-Tutorial\jboss-4.0.3SP1
JAVA: /cygdrive/c/Program Files/Java/jdk1.5.0_06/bin/java
JAVA_OPTS: -server -Xms128m -Xmx128m -Dprogram.name=run.sh
CLASSPATH: d:\java\JBossTS-JBoss-Tutorial\jboss-4.0.3SP1\bin\run.jar;c:\Program Files\Java\jdk1.5.0_06\lib\tools.jar
=========================================================================
10:29:39,300 INFO [Server] Starting JBoss (MX MicroKernel)...
10:29:39,300 INFO [Server] Release ID: JBoss [Zion] 4.0.3SP1 (build: CVSTag=JBoss_4_0_3_SP1 date=200510231054)
10:29:39,300 INFO [Server] Home Dir: D:\java\JBossTS-JBoss-Tutorial\jboss-4.0.3SP1
10:29:39,300 INFO [Server] Home URL: file:/D:/java/JBossTS-JBoss-Tutorial/jboss-4.0.3SP1/
10:29:39,300 INFO [Server] Patch URL: null
10:29:39,300 INFO [Server] Server Name: all
10:29:39,300 INFO [Server] Server Home Dir: D:\java\JBossTS-JBoss-Tutorial\jboss-4.0.3SP1\server\all
10:29:39,300 INFO [Server] Server Home URL: file:/D:/java/JBossTS-JBoss-Tutorial/jboss-4.0.3SP1/server/all/
10:29:39,300 INFO [Server] Server Temp Dir: D:\java\JBossTS-JBoss-Tutorial\jboss-4.0.3SP1\server\all\tmp
10:29:39,300 INFO [Server] Root Deployment Filename: jboss-service.xml
10:29:39,597 INFO [ServerInfo] Java version: 1.5.0_06,Sun Microsystems Inc.
10:29:39,597 INFO [ServerInfo] Java VM: Java HotSpot(TM) Server VM 1.5.0_06-b05,Sun Microsystems Inc.
10:29:39,597 INFO [ServerInfo] OS-System: Windows XP 5.1,x86
10:29:40,159 INFO [Server] Core system initialized
10:29:42,909 INFO [WebService] Using RMI server codebase: http://paul-lt:8083/
10:29:42,925 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
10:29:43,206 INFO [NamingService] Started jndi bootstrap jnpPort=1099, rmiPort=1098, backlog=50, bindAddress=/0.0.0.0,
Client SocketFactory=null, Server SocketFactory=org.jboss.net.sockets.DefaultSocketFactory@ad093076
10:29:47,409 INFO [SnmpAgentService] SNMP agent going active
10:29:47,924 INFO [DefaultPartition] Initializing
10:29:47,956 INFO [STDOUT]
-------------------------------------------------------
GMS: address is paul-lt:1210 (additional data: 16 bytes)
-------------------------------------------------------
10:29:49,971 INFO [DefaultPartition] Number of cluster members: 1
10:29:49,971 INFO [DefaultPartition] Other members: 0
10:29:49,971 INFO [DefaultPartition] Fetching state (will wait for 30000 milliseconds):
10:29:49,971 INFO [DefaultPartition] New cluster view for partition DefaultPartition (id: 0, delta: 0) : [10.9.10.182:1
099]
10:29:49,987 INFO [DefaultPartition] I am (10.9.10.182:1099) received membershipChanged event:
10:29:49,987 INFO [DefaultPartition] Dead members: 0 ([])
10:29:49,987 INFO [DefaultPartition] New Members : 0 ([])
10:29:49,987 INFO [DefaultPartition] All Members : 1 ([10.9.10.182:1099])
10:29:50,018 INFO [HANamingService] Started ha-jndi bootstrap jnpPort=1100, backlog=50, bindAddress=/0.0.0.0
10:29:50,034 INFO [DetachedHANamingService$AutomaticDiscovery] Listening on /0.0.0.0:1102, group=230.0.0.4, HA-JNDI add
ress=10.9.10.182:1100
10:29:51,377 INFO [TransactionManagerService] JBossTS Transaction Service - JBoss Inc.
10:29:51,377 INFO [TransactionManagerService] Setting up property manager MBean and JMX layer
10:29:51,377 INFO [orb] ORB run
10:29:51,424 INFO [tsmxLogger] Registering mbean for module 'arjuna'
10:29:51,440 INFO [tsmxLogger] Initialising JMX agent com.arjuna.ats.internal.jbossatx.agent.LocalJBossAgentImpl
10:29:51,455 INFO [tsmxLogger] Registering mbean for module 'jts'
10:29:51,455 INFO [tsmxLogger] Registering mbean for module 'jta'
10:29:51,455 INFO [tsmxLogger] Registering mbean for module 'txoj'
10:29:51,502 INFO [loggerI18N] [com.arjuna.orbportability.internal.utils.InitLoader.loading] Loading PostSetLoader clas
s - com.arjuna.ats.internal.jts.recovery.RecoveryInit
10:29:51,534 INFO [loggerI18N] [com.arjuna.orbportability.internal.utils.InitLoader.loading] Loading PostSetLoader clas
s - com.arjuna.ats.jts.utils.ORBSetup
10:29:51,565 INFO [TransactionManagerService] Starting recovery manager
10:29:51,612 INFO [arjLogger]
--- Start RecoveryActivators
10:29:51,627 INFO [loggerI18N] [com.arjuna.ats.internal.jts.orbspecific.jacorb.recoverycoordinators.JacOrbRCServiceInit
_6a] [com.arjuna.ats.internal.jts.orbspecific.jacorb.recoverycoordinators.JacOrbRCServiceInit_6a] - Sharing RecoveryServ
er ORB on port
10:29:51,752 INFO [arjLoggerI18N] [com.arjuna.ats.arjuna.recovery.TransactionStatusManager_1] - Starting service com.ar
juna.ats.arjuna.recovery.ActionStatusService on port 1212
10:29:51,752 INFO [arjLogger] TransactionStatusManagerItem - host: 10.9.10.182 port: 1212
10:29:51,768 INFO [arjLoggerI18N] [com.arjuna.ats.arjuna.recovery.TransactionStatusManager_3] - TransactionStatusManage
r started on port 1212 with service com.arjuna.ats.arjuna.recovery.ActionStatusService
10:29:51,768 INFO [orb] ORB run
10:29:51,846 INFO [arjLogger]
--- ExpiredEntryMonitor ----Tue, 9 May 2006 10:29:51----
10:29:51,924 INFO [loggerI18N] [com.arjuna.ats.internal.jta.recovery.noxanodes] No XA recovery nodes specified. Will on
ly recover saved states.
10:29:51,924 INFO [loggerI18N] [com.arjuna.ats.internal.jta.recovery.noxanodes] No XA recovery nodes specified. Will on
ly recover saved states.
10:29:51,924 INFO [arjLogger] RecoveryManagerImple is ready on port 1214
10:29:51,924 INFO [arjLogger] Periodic recovery - first pass <Tue, 9 May 2006 10:29:51>
10:29:51,924 INFO [TransactionManagerService] Recovery manager started
10:29:51,924 INFO [arjLogger] StatusModule: first pass
10:29:51,924 INFO [TransactionManagerService] Binding TransactionManager JNDI Reference
10:29:51,924 INFO [txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - firs
t pass
10:29:51,924 INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryModule_3]
[com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryModule_3] - TopLevelTransactionRecoveryMod
ule First Pass
10:29:51,924 INFO [logger] TransactionRecoveryModule.periodicWorkFirstPass()
10:29:51,940 INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule_3] [c
om.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule_3] - ServerTransactionRecoveryModule -
First Pass
10:29:51,940 INFO [logger] TransactionRecoveryModule.periodicWorkFirstPass()
10:29:51,940 INFO [logger] Local XARecoveryModule - first pass
10:29:51,940 INFO [logger] JTS XARecoveryModule - first pass
10:29:52,127 INFO [CorbaNamingService] Naming: [IOR:000000000000002B49444C3A6F6D672E6F72672F436F734E616D696E672F4E616D6
96E67436F6E746578744578743A312E3000000000000200000000000000D8000102000000000C31302E392E31302E313832000DC80000000000114A4
26F73732F4E616D696E672F726F6F74000000000000050000000000000008000000004A414300000000010000001C000000000001000100000001050
100010001010900000001050100010000002100000050000000000000000100000000000000240000001E0000007E00000000000000010000000C313
02E392E31302E313832000DC90000000000000000000000000000000000000000000000000000000000000000002000000004000000000000001F000
0000400000003000000010000002000000000000000020000002000000004000000000000001F0000000400000003]
10:29:52,205 INFO [CorbaTransactionService] TransactionFactory: [IOR:000000000000003049444C3A6F72672F6A626F73732F746D2F
69696F702F5472616E73616374696F6E466163746F72794578743A312E30000000000200000000000000D8000102000000000C31302E392E31302E31
3832000DC80000000000144A426F73732F5472616E73616374696F6E732F46000000050000000000000008000000004A414300000000010000001C00
0000000001000100000001050100010001010900000001050100010000002100000050000000000000000100000000000000240000001E0000007E00
000000000000010000000C31302E392E31302E313832000DC90000000000000000000000000000000000000000000000000000000000000000002000
000004000000000000001F0000000400000003000000010000002000000000000000020000002000000004000000000000001F0000000400000003]
10:29:53,455 INFO [MailService] Mail Service bound to java:/Mail
10:29:53,643 INFO [TreeCache] setting cluster properties from xml to: UDP(ip_mcast=true;ip_ttl=8;loopback=false;mcast_a
ddr=230.1.2.7;mcast_port=45577;mcast_recv_buf_size=80000;mcast_send_buf_size=150000;ucast_recv_buf_size=80000;ucast_send
_buf_size=150000):PING(down_thread=false;num_initial_members=3;timeout=2000;up_thread=false):MERGE2(max_interval=20000;m
in_interval=10000):FD_SOCK:VERIFY_SUSPECT(down_thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(down_thread=fals
e;gc_lag=50;max_xmit_size=8192;retransmit_timeout=600,1200,2400,4800;up_thread=false):UNICAST(down_thread=false;min_thre
shold=10;timeout=600,1200,2400;window_size=100):pbcast.STABLE(desired_avg_gossip=20000;down_thread=false;up_thread=false
):FRAG(down_thread=false;frag_size=8192;up_thread=false):pbcast.GMS(join_retry_timeout=2000;join_timeout=5000;print_loca
l_addr=true;shun=true):pbcast.STATE_TRANSFER(down_thread=true;up_thread=true)
10:29:53,658 INFO [TreeCache] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.LockInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
10:29:53,658 INFO [TreeCache] cache mode is REPL_ASYNC
10:29:53,674 INFO [STDOUT]
-------------------------------------------------------
GMS: address is paul-lt:1217
-------------------------------------------------------
10:29:55,690 INFO [TreeCache] state could not be retrieved (must be first member in group)
10:29:55,690 INFO [TreeCache] viewAccepted(): new members: [paul-lt:1217]
10:29:55,690 INFO [TreeCache] new cache is null (maybe first member in cluster)
10:29:55,815 INFO [Embedded] Catalina naming disabled
10:29:56,455 INFO [Http11Protocol] Initializing Coyote HTTP/1.1 on http-0.0.0.0-8080
10:29:56,455 INFO [Catalina] Initialization processed in 594 ms
10:29:56,455 INFO [StandardService] Starting service jboss.web
10:29:56,455 INFO [StandardEngine] Starting Servlet Engine: Apache Tomcat/5.5
10:29:56,502 INFO [StandardHost] XML validation disabled
10:29:56,627 INFO [Catalina] Server startup in 172 ms
10:29:56,736 INFO [TomcatDeployer] deploy, ctxPath=/invoker, warUrl=.../deploy/httpha-invoker.sar/invoker.war/
10:29:57,018 INFO [WebappLoader] Dual registration of jndi stream handler: factory already defined
10:29:57,486 INFO [TomcatDeployer] deploy, ctxPath=/ws4ee, warUrl=.../tmp/deploy/tmp62851jboss-ws4ee-exp.war/
10:29:57,830 INFO [TomcatDeployer] deploy, ctxPath=/, warUrl=.../deploy/jbossweb-tomcat55.sar/ROOT.war/
10:29:58,002 INFO [TomcatDeployer] deploy, ctxPath=/juddi, warUrl=.../deploy/juddi-service.sar/juddiws.war/
10:29:58,127 INFO [RegistryServlet] Loading jUDDI configuration.
10:29:58,127 INFO [RegistryServlet] Resources loaded from: /WEB-INF/juddi.properties
10:29:58,127 INFO [RegistryServlet] Initializing jUDDI components.
10:29:58,439 INFO [TomcatDeployer] deploy, ctxPath=/web-console, warUrl=.../deploy/management/console-mgr.sar/web-conso
le.war/
10:29:58,924 INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../deploy-hasingleton/jms/jbossmq-httpil.sa
r/jbossmq-httpil.war/
10:29:59,330 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-local-jdbc.
rar
10:29:59,502 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-xa-jdbc.rar
10:29:59,674 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-local-jdbc.rar
10:30:00,111 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-xa-jdbc.rar
10:30:00,268 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jms/jms-ra.rar
10:30:00,377 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/mail-ra.rar
10:30:01,596 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=D
efaultDS' to JNDI name 'java:DefaultDS'
10:30:01,955 INFO [arjLogger] Periodic recovery - second pass <Tue, 9 May 2006 10:30:01>
10:30:01,955 INFO [arjLogger] AtomicActionRecoveryModule: Second pass
10:30:01,955 INFO [txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - seco
nd pass
10:30:01,955 INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryModule_4]
[com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryModule_4] - TopLevelTransactionRecoveryMod
ule Second Pass
10:30:01,955 INFO [logger] TransactionRecoveryModule.periodicWorkSecondPass()
10:30:01,955 INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule_4] [c
om.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule_4] - ServerTransactionRecoveryModule -
Second Pass
10:30:01,955 INFO [logger] Local XARecoveryModule - second pass
10:30:01,955 INFO [logger] JTS XARecoveryModule - second pass
10:30:02,096 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,096 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,158 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,158 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,189 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,205 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,267 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,299 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,299 INFO [A] Bound to JNDI name: queue/A
10:30:02,314 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,330 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,330 INFO [B] Bound to JNDI name: queue/B
10:30:02,377 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,377 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,377 INFO [C] Bound to JNDI name: queue/C
10:30:02,408 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,424 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,424 INFO [D] Bound to JNDI name: queue/D
10:30:02,517 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,533 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,533 INFO [ex] Bound to JNDI name: queue/ex
10:30:02,611 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,611 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,642 INFO [testTopic] Bound to JNDI name: topic/testTopic
10:30:02,658 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,674 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,674 INFO [securedTopic] Bound to JNDI name: topic/securedTopic
10:30:02,721 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,736 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,736 INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic
10:30:02,752 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,752 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,752 INFO [testQueue] Bound to JNDI name: queue/testQueue
10:30:02,799 INFO [UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093
10:30:02,861 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,861 INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
10:30:02,861 INFO [DLQ] Bound to JNDI name: queue/DLQ
10:30:03,017 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding
,name=JmsXA' to JNDI name 'java:JmsXA'
10:30:03,049 INFO [TomcatDeployer] deploy, ctxPath=/jmx-console, warUrl=.../deploy/jmx-console.war/
10:30:03,408 INFO [Http11Protocol] Starting Coyote HTTP/1.1 on http-0.0.0.0-8080
10:30:03,517 INFO [ChannelSocket] JK: ajp13 listening on /0.0.0.0:8009
10:30:03,533 INFO [JkMain] Jk running ID=0 time=0/31 config=null
10:30:03,549 INFO [Server] JBoss (MX MicroKernel) [4.0.3SP1 (build: CVSTag=JBoss_4_0_3_SP1 date=200510231054)] Started
in 24s:249ms