1 2 Previous Next 21 Replies Latest reply on May 17, 2006 9:23 AM by Mark Little

    java.lang.OutOfMemoryError: Requested array size exceeds VM

    Paul Robinson Master

      Hello,

      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

        • 1. Re: java.lang.OutOfMemoryError: Requested array size exceeds
          Paul Robinson Master

          I should add, I've tried editing run.sh and added the following to the java startup options:

          -Xms128m -Xmx512m

          Thus setting the initial heap size to 128Mb and the maximum heap size to 512Mb. I get the same exceptions

          Paul.

          • 2. Re: java.lang.OutOfMemoryError: Requested array size exceeds
            Kevin Conner Master

            Well the first step is to find out what is consuming the memory.

            I would attack the issue as follows

            - attach a debugger and trap the exception
            This will show where the exception is being raised and may indicate
            the problem, i.e. if some code is trying to allocate a 512MB array ;-)
            - get a profiler and look through the memory allocations
            This will show you exactly what objects are consuming the memory.

            If this is related to JBossTS then it may depend on the contents of your object store directory. Please make a copy of this directory prior to any investigation so that we may use it to identify any possible issues with the JBossTS codebase.

            We ran 4.0.3SP1 + JBossTS with the complete JBoss testsuite and have never seen this issue.

            Also, attaching jconsole (I noticed you are using 1.5) to a clean installation shows a heap running at around 25MB on my local linux box.

            If you need any more help diagnosing this then please let me know.

            Thanks,
            Kev

            • 3. Re: java.lang.OutOfMemoryError: Requested array size exceeds
              Narasinga Rao Kalagarla Newbie

              Hi Keven,

              I have similar problem. I have installed JBossTS 4.2 into is a fresh JBoss 4.0.3SP1 'all' server instance. I didn't deploy any application in this instance. There are many OutOfMemoryErrors in the server startup.

              INFO [TomcatDeployer] deploy, ctxPath=/web-console, warUrl=.../deploy/management/console-mgr.sar/web-console.war/
              INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../deploy-hasingleton/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-local-jdbc.rar
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-xa-jdbc.rar
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-local-jdbc.rar
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-xa-jdbc.rar
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jms/jms-ra.rar
              INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/mail-ra.rar
              INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:DefaultDS'
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [A] Bound to JNDI name: queue/A
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [B] Bound to JNDI name: queue/B
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [C] Bound to JNDI name: queue/C
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [D] Bound to JNDI name: queue/D
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [ex] Bound to JNDI name: queue/ex
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [testTopic] Bound to JNDI name: topic/testTopic
              INFO [arjLogger] Periodic recovery - second pass <Tue, 9 May 2006 16:21:43>
              INFO [arjLogger] AtomicActionRecoveryModule: Second pass
              INFO [txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
              INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryModule_4] [com.arjuna.ats.internal.jts.recovery.transactions.TopLevelTransactionRecoveryMo
              LevelTransactionRecoveryModule Second Pass
              INFO [logger] TransactionRecoveryModule.periodicWorkSecondPass()
              INFO [loggerI18N] [com.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule_4] [com.arjuna.ats.internal.jts.recovery.transactions.ServerTransactionRecoveryModule
              ransactionRecoveryModule - Second Pass
              INFO [logger] Local XARecoveryModule - second pass
              INFO [logger] JTS XARecoveryModule - second pass
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [securedTopic] Bound to JNDI name: topic/securedTopic
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [testQueue] Bound to JNDI name: queue/testQueue
              INFO [UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit
              INFO [STDOUT] java.lang.OutOfMemoryError: Requested array size exceeds VM limit

              Thanks,
              Rao

              • 4. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                Kevin Conner Master

                Hiya Rao.

                One of Paul's colleagues has managed to do some further investigation into this problem. They have produced a stacktrace which could suggest a problem in the JacORB layer although, as with any OOM, the symptoms exhibited do not necessarily reflect the cause.

                I am trying to arrange time to help them diagnose the issue, their office is directly above mine, and will update this entry when we have more information.

                I am sorry you have had this problem with JBossTS. I am trying to identify the cause as quickly as possible.

                Kev

                • 5. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                  Kevin Conner Master

                  Paul, Rao.

                  An update on progress.

                  Investigation is showing that there appears to be an intermittent issue with the marshalling/unmarshalling of the OTS propagation context. The OOM are occurring when a corrupted context is being received on the server side.

                  We are trying to identify the cause of this but, in the mean time, there appears to be a workaround.

                  There is a version of JacORB on the TS download page that does not appear to suffer from this issue. It is a modified version of JacORB 2.2.2 and can be used instead of the version in AS 4.0.3 SP1. The jacorb.jar file in the download should be placed into the server/all/lib directory, in place of the current version of jacorb.jar. I believe this combination has already been tested by the QA team.

                  We are continuing to investigate this issue so that we can be sure it has been resolved.

                  Kev

                  • 6. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                    Peter Potthoff Newbie

                    Hello,

                    I remarked this error last week, while evaluating the jts package.
                    I recompiled the arjuna packages, the jacorb 2.2.1 and debugged
                    the arjuna corba interceptor. (InterpositionServerRequestInterceptorImpl)
                    In my application I found two kinds of incoming messages in the
                    servicecontext.context_data parameter of the method receive_request_service_contexts.

                    [0, 0, 0, 0, 0, 0, 2, -115, 73, 79, 82, 58, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 50, 70, 52, 57, 52, 52, 52, 67, 51, 65, 54, 49, 55, 50, 54, 65, 55, 53, 54, 69, 54, 49, 50, 69, 54, 51, 54, 70, 54, 68, 50, 70, 52, 49, 55, 50, 54, 65, 55, 53, 54, 69, 54, 49, 52, 70, 53, 52, 53, 51, 50, 70, 52, 49, 55, 50, 54, 65, 55, 53, 54, 69, 54, 49, 53, 52, 55, 50, 54, 49, 54, 69, 55, 51, 54, 49, 54, 51, 55, 52, 54, 57, 54, 70, 54, 69, 51, 65, 51, 49, 50, 69, 51, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 50, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 68, 56, 48, 48, 48, 49, 48, 50, 48, 48, 48, 48, 48, 48, 48, 48, 48, 67, 51, 49, 51, 48, 50, 69, 51, 52, 51, 51, 50, 69, 51, 50, 50, 69, 51, 49, 51, 49, 51, 49, 48, 48, 48, 68, 67, 56, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 49, 52, 65, 52, 50, 54, 70, 55, 51, 55, 51, 50, 70, 48, 50, 48, 65, 49, 52, 51, 54, 49, 56, 48, 49, 52, 50, 51, 53, 50, 67, 48, 54, 52, 66, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 53, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 56, 48, 48, 48, 48, 48, 48, 48, 48, 52, 65, 52, 49, 52, 51, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 49, 67, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 48, 49, 48, 53, 48, 49, 48, 48, 48, 49, 48, 48, 48, 49, 48, 49, 48, 57, 48, 48, 48, 48, 48, 48, 48, 49, 48, 53, 48, 49, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 50, 49, 48, 48, 48, 48, 48, 48, 53, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 50, 52, 48, 48, 48, 48, 48, 48, 49, 69, 48, 48, 48, 48, 48, 48, 55, 69, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 48, 67, 51, 49, 51, 48, 50, 69, 51, 52, 51, 51, 50, 69, 51, 50, 50, 69, 51, 49, 51, 49, 51, 49, 48, 48, 48, 68, 67, 57, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 50, 48, 48, 48, 48, 48, 48, 48, 48, 52, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 70, 48, 48, 48, 48, 48, 48, 48, 52, 48, 48, 48, 48, 48, 48, 48, 51, 48, 48, 48, 48, 48, 48, 48, 49, 48, 48, 48, 48, 48, 48, 50, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 50, 48, 48, 48, 48, 48, 48, 50, 48, 48, 48, 48, 48, 48, 48, 48, 52, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 49, 70, 48, 48, 48, 48, 48, 48, 48, 52, 48, 48, 48, 48, 48, 48, 48, 51, 0]

                    [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 47, 73, 68, 76, 58, 97, 114, 106, 117, 110, 97, 46, 99, 111, 109, 47, 65, 114, 106, 117, 110, 97, 79, 84, 83, 47, 65, 114, 106, 117, 110, 97, 84, 114, 97, 110, 115, 97, 99, 116, 105, 111, 110, 58, 49, 46, 48, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 0, 0, -40, 0, 1, 2, 0, 0, 0, 0, 12, 49, 48, 46, 52, 51, 46, 50, 46, 49, 49, 49, 0, 13, -56, 0, 0, 0, 0, 0, 17, 74, 66, 111, 115, 115, 47, 2, 10, 20, 54, 24, 1, 66, 53, 44, 6, 75, 0, 0, 0, 0, 0, 0, 5, 0, 0, 0, 0, 0, 0, 0, 8, 0, 0, 0, 0, 74, 65, 67, 0, 0, 0, 0, 1, 0, 0, 0, 28, 0, 0, 0, 0, 0, 1, 0, 1, 0, 0, 0, 1, 5, 1, 0, 1, 0, 1, 1, 9, 0, 0, 0, 1, 5, 1, 0, 1, 0, 0, 0, 33, 0, 0, 0, 80, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 36, 0, 0, 0, 30, 0, 0, 0, 126, 0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 12, 49, 48, 46, 52, 51, 46, 50, 46, 49, 49, 49, 0, 13, -55, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 32, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 31, 0, 0, 0, 4, 0, 0, 0, 3, 0, 0, 0, 1, 0, 0, 0, 32, 0, 0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 32, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 31, 0, 0, 0, 4, 0, 0, 0, 3, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 27, 0, 0, 0, 27, 49, 45, 97, 50, 98, 48, 50, 54, 102, 58, 53, 99, 98, 58, 52, 52, 53, 102, 51, 100, 52, 98, 58, 51, 54, 50, 0, 0, 0, 0, 0, 0, 0, 0, 0, 2, 0, 0]

                    The first one caused the reported error - The second one could be processed.

                    I'm no corba expert, but i got the impression that the interceptor does
                    not distinguish between these messages and treats them both as
                    transactioncontext information. Doing this for the first message it tries
                    to unmarshal a string object at a false offset and interprets the wrong
                    bytes as string size ...

                    The first byte array contains an IOR Reference and the scond one
                    contains the following ascii information at position 11: /IDL:arjuna.com/ArjunaOTS/ArjunaTransaction:1.0

                    So, to continue my evaluation I made the following ( very primitive )
                    changes:

                    In receive_request_service_contexts I added an filter for the correct
                    message:

                    if (serviceContext != null) {
                    
                     if (contextDataContains(serviceContext, "/IDL:arjuna.com/ArjunaOTS/ArjunaTransaction:1.0")) {
                     Any receivedData = _codec.decode_value(serviceContext.context_data,
                     PropagationContextHelper.type());
                    
                     /*
                     * Set the slot information for the "current" thread. When the real
                     * invocation thread actually needs to get its transaction context it
                     * must check this slot (if it does not have a transaction context
                     * already) and then do a resume.
                     */
                    
                     request_info.set_slot(_dataSlot, receivedData);
                     }
                     } else {
                    

                    and a new method:
                    private boolean contextDataContains(ServiceContext ctx, String ident) {
                     if (ctx.context_data.length <= 11+ident.length())
                     return false;
                     String data = new String(ctx.context_data, 11, ident.length());
                     return ident.equals(data);
                    }
                    


                    This testversion stopped the OutOfMemory Exception and my distributed transactions were still working.

                    I'm sure that this is not the corba way to solve this problem, but I hope this posting can help finding the reason for this error.

                    Peter


                    • 7. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                      Kevin Conner Master

                      I discovered the cause of the problem yesterday evening but I was trying to understand why it would work in the JacORB 2.2.2 and not the 2.2.1 version. The issue should exist with both versions of JacORB, but then again I know that it works on my linux box :-(

                      The first point to note is that this OOM has no bearing on the functionality of JTS. It is happening on an after_completion synchronisation call (which has no transaction context).

                      The problem occurs because there are two interceptors registered, one for normal context propagation and the other for interposition. These interceptors are mutually exclusive.

                      The interposition interceptor is trying to understand the standard context data and is interpreting the contents of a text string as a length (approx. 1GB). Hence the OOM :-)

                      I'm not sure why this configuration works in 2.2.2, it should fail in the same way, and I do not yet understand why it works in my 2.2.1 setup.

                      The solution to this is very simple though :-)

                      There are two places where the interceptors can be initialised, at least when running within JBoss AS. These are in the jacorb.properties or iiop-service.xml files. The installation instructions I produced for the release contains instructions to configure both locations but using two different interceptors. This is incorrect.

                      All that is required is to fix this is to comment out the definition of the interceptor in jacorb.properties, i.e. the line containing InterpositionORBInitializerImpl.

                      Apologies for the problems, I am updating the installation notes to fix this.

                      Kev

                      • 8. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                        Kevin Conner Master

                        I should add that using the patched JacORB 2.2.2 release is not required to fix this issue but it is advisable.

                        The patched version contains a loopback transport layer which I wrote to increase the performance of intra vm CORBA calls. This significantly increases the performance of intra VM calls if those calls are configured to use interceptors (which they will be with TS).

                        Kev

                        • 9. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                          Mark Little Master

                          Just a note. The differences between the two interceptors is this:

                          (i) context propagation - this will only propagate the current context between client and server. No interposition (subordinate coordinator useage) will occur.

                          (ii) interposition - this propagates the entire transaction hierarchy between client and server. Interposition occurs at the server side.

                          By default, as Kevin mentions, the current JBossTS install into JBossAS uses (i). If you want to go with interposition (which may offer better performance in the presence of multiple resource registrations), then change the interceptor property to utilise the other implementation.

                          • 11. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                            Peter Potthoff Newbie

                            Hi Kevin,

                            if I got you right I just have to remove one line from jacorb.properties:

                            org.omg.PortableInterceptor.ORBInitializerClass.com.arjuna.ats.jts.orbspecific.jacorb.interceptors.interposition.InterpositionORBInitializerImpl=com.arjuna.ats.jts.orbspecific.jacorb.interceptors.interposition.InterpositionORBInitializerImpl

                            If I do this, the OutOfMemoryException does not occur any longer but
                            in my sample application every distributed tx is rolled back.
                            If I ignore a part of the messages, see my first posting, the transactions
                            were committed.

                            My test application is connected to 2 JBoss app-server, both having the
                            arjuna jts-package installed. I start the CMT transaction on server 1
                            connect to a db2 database and include the server 2 connected to a
                            different db2 instance.

                            Do I need interposition for this job or can I use context propagation?
                            Which config properties do I have to change to realize this scenario?

                            Peter

                            • 12. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                              Mark Little Master

                              Using the context interceptor versus the interposition interceptor should make no difference to the outcome of your transactions.

                              Can you try with the patched version of JacORB (it's available from the download page you got JBossTS from)?

                              If that doesn't work, what error messages do you get during commit/rollback?

                              • 13. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                                Kevin Conner Master

                                Hiya Peter.

                                if I got you right I just have to remove one line from jacorb.properties:

                                Yes, that's correct. Removing this line results in only a single interceptor being registered, the one present in iiop-service.xml.

                                As Mark says, interposition shouldn't make a difference but please try it. You should replace the Context initializer class in iiop-service.xml with the one mentioned in jacorb.properties (the property value). The result of using interposition is that your second DB2 instance will be registered with the coordinator in the second app server instance instead of with the first app server instance.

                                BTW What is your network topology? Does the second DB2 instance have access to the first app server?

                                Could you please provide the errors being reported when the transactions are rolled back?
                                My test application is connected to 2 JBoss app-server, both having the
                                arjuna jts-package installed. I start the CMT transaction on server 1
                                connect to a db2 database and include the server 2 connected to a
                                different db2 instance.

                                DB2 is not a database we qualify against, is it possible for you to try your test using Oracle or SQL Server 2000?

                                Kev


                                • 14. Re: java.lang.OutOfMemoryError: Requested array size exceeds
                                  Peter Potthoff Newbie

                                  Sorry, I have no other database to test my transaction demo.
                                  My network consists of three physical server. Two database server
                                  which have no direct route between them and one machine with
                                  two jboss instances using different ports.

                                  Both app server have only access to their database. ( They have only
                                  one database deployment descriptor. )

                                  One thing I noticed when switching from interposition to interception
                                  is a different behaviour of the CachedConnectionManager.
                                  I received messages that the connection manager closed my connection
                                  on behalf of me. Do I have to set the debug attribute of the CachedConnectionManager (jbossjca-service.xml) to false in order to process distributed TX?

                                  Why didn't I receive those messages when using interposition?

                                  I'm not able to post the exact stacktrace and error message because
                                  of another database problem that I'll have to fix first. I will post it, as soon
                                  as I am able to reproduce the error.


                                  1 2 Previous Next