8 Replies Latest reply on May 6, 2008 4:15 AM by Tim Fox

    OutOfMemoryError with JBoss Messaging

    Harish Krishnamurthy Newbie

      I am getting java.lang.OutOfMemoryError after a few hours when running a load test with the following setup.
      JBoss AS 4.2.2 GA
      JBM 1.4.0 SP3
      JBoss Remoting 2.4.0.CR1 (Pinto)
      JDK 1.5.0_06
      JVM arguments : -verbose:gc -XX:+PrintGCTimeStamps -XX:NewRatio=1 -Xms1024m -Xmx2048m -XX:PermSize=128m -XX:MaxPermSize=256m -XX:+UseParallelGC -Dsun.rmi.dgc.client.gcInterval=120000 -Dsun.rmi.dgc.server.gcInterval=120000

      The Full GC times increase from 1 second at the beginning to 30 seconds in the end. The Old generation space gets filled to the max of 1GB and after sometime the Eden space is filled up to its max and GCs cannot claim any more space.

      The memory usage is very stable when testing with JBossMQ.

      The jboss remoting objects seem to be growing throughout the test. When testing with JBossMQ the jboss remoting objects are pretty stable and not nearly as many instances as with JBM.

      I have tried with JBoss Remoting version 2.2.2.SP4-brew as recommended in the JBM 1.4.0 SP3 documentation and I get the same behavior.


      Below is a heap snapshot towards the end of the test.



      769946 .. 168189k . char[]
      2814906 . 98961k .. java.util.HashMap$Entry
      936726 .. 88564k .. java.util.HashMap$Entry[]
      2008055 . 54907k .. java.lang.String
      936446 .. 51211k .. java.util.HashMap
      434925 .. 25114k .. java.lang.Object[]
      634584 .. 22309k .. java.util.Hashtable$Entry
      1788960 . 20964k .. EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Segment (CL #2)
      389365 .. 18631k .. java.util.TreeMap$Entry
      45601 ... 14903k .. byte[]
      27873 ... 11840k .. org.jboss.remoting.transport.bisocket.BisocketServerInvoker (CL #4)
      243018 .. 11391k .. java.util.Collections$SynchronizedMap
      86909 ... 9109k ... java.util.Hashtable$Entry[]
      102026 .. 7970k ... nu.xom.Element (CL #78)
      55905 ... 7872k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Entry[] (CL #2)
      55905 ... 7861k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Segment[] (CL #2)
      306520 .. 7184k ... java.util.ArrayList
      55751 ... 6642k ... org.jboss.remoting.loading.ClassByteClassLoader (CL #4)
      28026 ... 5391k ... org.jboss.jms.server.endpoint.ServerSessionEndpoint (CL #4)
      75425 ... 5376k ... org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask (CL #4)
      28386 ... 4854k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap$Entry[] (CL #2)
      27872 ... 4545k ... org.jboss.jms.server.endpoint.ServerConnectionEndpoint (CL #4)
      55905 ... 4149k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap (CL #2)
      27917 ... 3953k ... org.jboss.remoting.Client (CL #4)
      6582 .... 3684k ... int[]
      98963 ... 3479k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap$Entry (CL #2)
      86490 ... 3378k ... java.lang.ref.WeakReference
      58692 ... 3209k ... java.util.Hashtable
      116937 .. 3197k ... java.util.Vector
      52948 ... 2895k ... java.util.TreeMap
      50254 ... 2748k ... nu.xom.Attribute (CL #78)
      27876 ... 2722k ... org.jboss.remoting.callback.ServerInvokerCallbackHandler (CL #4)
      84194 ... 2631k ... java.lang.ref.ReferenceQueue
      335308 .. 2619k ... java.lang.Object
      27903 ... 2506k ... org.jboss.remoting.InvokerLocator (CL #4)
      18018 ... 2410k ... java.lang.reflect.Method
      28386 ... 2328k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap (CL #2)
      28439 ... 2227k ... java.util.WeakHashMap$Entry[]
      140604 .. 2196k ... java.util.HashSet
      56231 ... 1976k ... EDU.oswego.cs.dl.util.concurrent.LinkedQueue (CL #2)
      27876 ... 1932k ... org.jboss.remoting.transport.local.LocalClientInvoker (CL #4)
      82629 ... 1901k ... nu.xom.Node[] (CL #78)
      28439 ... 1777k ... java.util.WeakHashMap
      28210 ... 1763k ... java.util.Properties
      28498 ... 1669k ... java.util.WeakHashMap$Entry
      28104 ... 1564k ... org.jboss.aop.ClassInstanceAdvisor (CL #109)
      27876 ... 1524k ... org.jboss.remoting.InvocationRequest (CL #4)
      27977 ... 1420k ... org.jboss.util.LRUCachePolicy$LRUList (CL #2)
      86154 ... 1346k ... java.util.HashMap$EntrySet
      56250 ... 1318k ... EDU.oswego.cs.dl.util.concurrent.LinkedNode (CL #2)
      28104 ... 1317k ... org.jboss.aop.InstanceAdvisorDelegate (CL #109)
      11647 ... 1296k ... org.jboss.mx.server.InvocationContext (CL #2)
      28029 ... 1122k ... EDU.oswego.cs.dl.util.concurrent.QueuedExecutor (CL #2)
      27875 ... 1116k ... org.jboss.remoting.transport.socket.LRUPool (CL #4)
      55778 ... 1089k ... org.jboss.remoting.Home (CL #4)
      27876 ... 1088k ... org.jboss.remoting.callback.DefaultCallbackErrorHandler (CL #4)


      I appreciate any help with this.

        • 1. Re: OutOfMemoryError with JBoss Messaging
          Andy Taylor Master

          what is your load test actually doing.

          have a look at http://www.jboss.org/file-access/default/members/jbossmessaging/freezone/docs/userguide-1.4.0.SP3/html/configuration.html#conf.destination.queue.attributes.paging.
          We page messages in/out of memory depending on these attribute settings, adjusting these could solve your problem!

          • 2. Re: OutOfMemoryError with JBoss Messaging
            Harish Krishnamurthy Newbie

            The test is processing xml documents.

            There is a servlet that is being fed one or more XML documents in every request. The servlet then creates a JMS message containing the document(s) and puts it on a queue. The MDB(s) listening on this queue is the controller. It sends a message corresponding to each step in the process to a different queue and there are MDBs that consume from each of the different queues. When the MDBs in each step is done with the message they send a message back to the control queue.

            The documents are normally 1K in size but occasionally can be larger or smaller than that.

            The first MDB is called the Dispatcher. It only is used if the request contained more than one document. It splits the request data into multiple documents and sends a message to the controller for each document.

            The second MDB is called the Master Processor. This is where each XML document is validated, compressed and persisted in the Sybase database. It sends a message to the controller after it is done.

            The third MDB is the Access Processor. This is where the XML document is converted to ASN.1 format and persisted in the Sybase database.

            All the queues are persistent.

            I tried setting the FullSize to 100 and the PageSize and DownCacheSize to 20 and the behavior is still the same.

            I keep getting a lot of errors as below and I am not sure why they are occuring and whether they have anything to do with the memory issue.

            ERROR [org.jboss.jms.client.container.ClosedInterceptor]
            ClosedInterceptor.ClientSessionDelegate[jr-i9awncff-1-q3osncff-g5axfp-2b2r6q3]: method createMapMessage() did not go through, the interceptor is CLOSED

            • 3. Re: OutOfMemoryError with JBoss Messaging
              Clebert Suconic Master

              27876 ... 1932k ... org.jboss.remoting.transport.local.LocalClientInvoker (CL #4)


              Are you using spring or something like that? It looks like you are not closing your JMS.Connections. It looks a leak in your code to me.

              • 4. Re: OutOfMemoryError with JBoss Messaging
                Harish Krishnamurthy Newbie

                I am not using Spring or any other framework. The same test works on JBossMQ. Is there any configuration in JBoss Messaging I am missing? I can post the JBM config files if needed.

                • 5. Re: OutOfMemoryError with JBoss Messaging
                  Andy Taylor Master

                  yes please. If you could simplify this in a testcase it may help as well.

                  • 6. Re: OutOfMemoryError with JBoss Messaging
                    Harish Krishnamurthy Newbie

                    Andy,

                    Sorry for the delay in responding to your request. I have a simple testcase to reproduce the issue.

                    I have run two tests with the queue example that comes with the JBoss Messaging distribution. The first test was to use the queue example to connect to a JBoss Messaging instance and the second test was to use the same queue example to connect to a JBossMQ instance. I used version 1.4.1.Beta1 of JBM in and version 4.0 of JBossMQ. The JBoss server version is 4.2.2.GA.

                    I enhanced the queue example to do the following steps 1 million times.

                    1. Lookup /ConnectionFactory
                    2. Lookup Queue
                    3. Create Connection
                    4. Create Session
                    5. Create Producer
                    6. Create Text Message
                    7. Send message
                    8. Create Consumer
                    9. Start the connection
                    10. Receive text message
                    11. Close connection

                    The JBossMQ test was twice as fast and consumed less memory overall. I had given 1GB for Eden and 1GB for old generation and the JBossMQ test used less than 80 MB of old generation throughout the test. I didn't see any of the MQ or remoting classes grow in number or size throughput the test.

                    In the JBM test the memory usage grew gradually over time and it used more than 400MB. I noticed the following classes grew.

                    At the beginning of the test



                    680 ..... 49k ..... org.jboss.remoting.transport.bisocket.BisocketClientInvoker$PingTimerTask (CL #4)
                    680 ..... 5k ...... org.jboss.remoting.transport.bisocket.BisocketClientInvoker$BooleanHolder (CL #4)
                    7 ....... 8k ...... java.util.TimerTask[]


                    At the end of the test



                    689030 .. 49793k .. org.jboss.remoting.transport.bisocket.BisocketClientInvoker$PingTimerTask (CL #4)
                    689030 .. 6055k ... org.jboss.remoting.transport.bisocket.BisocketClientInvoker$BooleanHolder (CL #4)
                    7 ....... 4102k ... java.util.TimerTask[]

                    The destinations-service.xml file is as below:

                    <?xml version="1.0" encoding="UTF-8"?>

                    <!--
                    Messaging Destinations deployment descriptor.

                    $Id: destinations-service.xml 1930 2007-01-09 18:16:04Z timfox $
                    -->



                    <!--
                    The Default Dead Letter Queue. This destination is a dependency of an EJB MDB container.
                    -->

                    <mbean code="org.jboss.jms.server.destination.QueueService"
                    name="jboss.messaging.destination:service=Queue,name=DLQ"
                    xmbean-dd="xmdesc/Queue-xmbean.xml">
                    <depends optional-attribute-name="ServerPeer">jboss.messaging:service=ServerPeer
                    jboss.messaging:service=PostOffice


                    <!--
                    The Default Expiry Queue.
                    -->

                    <mbean code="org.jboss.jms.server.destination.QueueService"
                    name="jboss.messaging.destination:service=Queue,name=ExpiryQueue"
                    xmbean-dd="xmdesc/Queue-xmbean.xml">
                    <depends optional-attribute-name="ServerPeer">jboss.messaging:service=ServerPeer
                    jboss.messaging:service=PostOffice


                    <mbean code="org.jboss.jms.server.destination.QueueService"
                    name="jboss.messaging.destination:service=Queue,name=testQueue"
                    xmbean-dd="xmdesc/Queue-xmbean.xml">
                    <depends optional-attribute-name="ServerPeer">jboss.messaging:service=ServerPeer
                    jboss.messaging:service=PostOffice




                    The connection-factories-service.xml file is as below:

                    <?xml version="1.0" encoding="UTF-8"?>

                    <!--
                    Messaging Connection Factories deployment descriptor.

                    $Id: connection-factories-service.xml 3332 2007-11-15 09:32:43Z timfox $
                    -->



                    <!-- The default connection factory does not support automatic failover or load balancing-
                    this is so we can maintain compatiblity with applications written for JBoss MQ which use this
                    connection factory.
                    -->
                    <mbean code="org.jboss.jms.server.connectionfactory.ConnectionFactory"
                    name="jboss.messaging.connectionfactory:service=ConnectionFactory"
                    xmbean-dd="xmdesc/ConnectionFactory-xmbean.xml">
                    <depends optional-attribute-name="ServerPeer">jboss.messaging:service=ServerPeer
                    <depends optional-attribute-name="Connector">jboss.messaging:service=Connector,transport=bisocket
                    jboss.messaging:service=PostOffice



                    /ConnectionFactory
                    /XAConnectionFactory
                    java:/ConnectionFactory
                    java:/XAConnectionFactory






                    I haven't modified the remoting-bisocket-service.xml and the messaging-service.xml files and the only change I made to the mysql-persistence-service.xml file is to set the Clustered attribute of the Post Office to false.

                    The modified queue example is below:
                    package org.jboss.example.jms.queue;

                    import javax.jms.Connection;
                    import javax.jms.ConnectionFactory;
                    import javax.jms.JMSException;
                    import javax.jms.MessageConsumer;
                    import javax.jms.MessageProducer;
                    import javax.jms.Queue;
                    import javax.jms.Session;
                    import javax.jms.TextMessage;
                    import javax.naming.InitialContext;

                    import org.jboss.example.jms.common.ExampleSupport;

                    /**
                    * This example creates a JMS Connection to a JBoss Messaging instance and uses it to create a
                    * session and a message producer, which sends a message to the queue "queue/testQueue". Then, the
                    * example uses the same connection to create a consumer that that reads a single message from the
                    * queue. The example is considered successful if the message consumer receives without any error
                    * the message that was sent by the producer.
                    *
                    * Since this example is also used by the smoke test, it is essential that the VM exits with exit
                    * code 0 in case of successful execution and a non-zero value on failure.
                    *
                    * @author Ovidiu Feodorov
                    * @author Luc Texier
                    * @author Tim Fox
                    * @version $Revision: 2868 $
                    *
                    * $Id: QueueExample.java 2868 2007-07-10 20:22:16Z timfox $
                    */
                    public class QueueExample extends ExampleSupport
                    {

                    public void example() throws Exception
                    {
                    String destinationName = getDestinationJNDIName();

                    InitialContext ic = null;
                    ConnectionFactory cf = null;
                    Connection connection = null;

                    try
                    {
                    for(long i = 0; i < 1000000; i++) {
                    ic = new InitialContext();

                    cf = (ConnectionFactory)ic.lookup("/ConnectionFactory");
                    Queue queue = (Queue)ic.lookup(destinationName);
                    log("Queue " + destinationName + " exists");

                    connection = cf.createConnection();
                    Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
                    MessageProducer sender = session.createProducer(queue);

                    TextMessage message = session.createTextMessage("Hello!");
                    sender.send(message);
                    log("Message #" + i);
                    log("The message was successfully sent to the " + queue.getQueueName() + " queue");
                    MessageConsumer consumer = session.createConsumer(queue);

                    connection.start();

                    message = (TextMessage)consumer.receive();

                    log("Received message: " + message.getText());
                    assertEquals("Hello!", message.getText());

                    displayProviderInfo(connection.getMetaData());
                    closeConnection(connection);
                    }
                    }
                    finally
                    {
                    if(ic != null)
                    {
                    try
                    {
                    ic.close();
                    }
                    catch(Exception e)
                    {
                    throw e;
                    }
                    }

                    // ALWAYS close your connection in a finally block to avoid leaks.
                    // Closing connection also takes care of closing its related objects e.g. sessions.
                    closeConnection(connection);
                    }
                    }

                    private void closeConnection(Connection con)
                    {
                    try
                    {
                    if (con != null)
                    {
                    con.close();
                    }
                    }
                    catch(JMSException jmse)
                    {
                    log("Could not close connection " + con +" exception was " + jmse);
                    }
                    }

                    protected boolean isQueueExample()
                    {
                    return true;
                    }

                    public static void main(String[] args)
                    {
                    new QueueExample().run();
                    }

                    }

                    I have also tried with moving the two lookups to outside of the for loop with similar results.

                    The question I have is why are the org.jboss.remoting.transport.bisocket.BisocketClientInvoker$PingTimerTask and the org.jboss.remoting.transport.bisocket.BisocketClientInvoker$BooleanHolder classes are growing over time?

                    Please let me know if you need any more information.

                    Harish.

                    • 7. Re: OutOfMemoryError with JBoss Messaging
                      Tim Fox Master

                       

                      "harish43" wrote:

                      1. Lookup /ConnectionFactory
                      2. Lookup Queue
                      3. Create Connection
                      4. Create Session
                      5. Create Producer
                      6. Create Text Message
                      7. Send message
                      8. Create Consumer
                      9. Start the connection
                      10. Receive text message
                      11. Close connection


                      Short answer: Don't do this!

                      It's a classic anti-pattern to lookup, create connection, create session etc for each message.

                      This will be very slow. Look ups, connection creation, session creation etc are _heavyweight_ operations.




                      • 8. Re: OutOfMemoryError with JBoss Messaging
                        Tim Fox Master

                         

                        "harish43" wrote:
                        I

                        769946 .. 168189k . char[]
                        2814906 . 98961k .. java.util.HashMap$Entry
                        936726 .. 88564k .. java.util.HashMap$Entry[]
                        2008055 . 54907k .. java.lang.String
                        936446 .. 51211k .. java.util.HashMap
                        434925 .. 25114k .. java.lang.Object[]
                        634584 .. 22309k .. java.util.Hashtable$Entry
                        1788960 . 20964k .. EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Segment (CL #2)
                        389365 .. 18631k .. java.util.TreeMap$Entry
                        45601 ... 14903k .. byte[]
                        27873 ... 11840k .. org.jboss.remoting.transport.bisocket.BisocketServerInvoker (CL #4)
                        243018 .. 11391k .. java.util.Collections$SynchronizedMap
                        86909 ... 9109k ... java.util.Hashtable$Entry[]
                        102026 .. 7970k ... nu.xom.Element (CL #78)
                        55905 ... 7872k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Entry[] (CL #2)
                        55905 ... 7861k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap$Segment[] (CL #2)
                        306520 .. 7184k ... java.util.ArrayList
                        55751 ... 6642k ... org.jboss.remoting.loading.ClassByteClassLoader (CL #4)
                        28026 ... 5391k ... org.jboss.jms.server.endpoint.ServerSessionEndpoint (CL #4)
                        75425 ... 5376k ... org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask (CL #4)
                        28386 ... 4854k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap$Entry[] (CL #2)
                        27872 ... 4545k ... org.jboss.jms.server.endpoint.ServerConnectionEndpoint (CL #4)
                        55905 ... 4149k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentHashMap (CL #2)
                        27917 ... 3953k ... org.jboss.remoting.Client (CL #4)
                        6582 .... 3684k ... int[]
                        98963 ... 3479k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap$Entry (CL #2)
                        86490 ... 3378k ... java.lang.ref.WeakReference
                        58692 ... 3209k ... java.util.Hashtable
                        116937 .. 3197k ... java.util.Vector
                        52948 ... 2895k ... java.util.TreeMap
                        50254 ... 2748k ... nu.xom.Attribute (CL #78)
                        27876 ... 2722k ... org.jboss.remoting.callback.ServerInvokerCallbackHandler (CL #4)
                        84194 ... 2631k ... java.lang.ref.ReferenceQueue
                        335308 .. 2619k ... java.lang.Object
                        27903 ... 2506k ... org.jboss.remoting.InvokerLocator (CL #4)
                        18018 ... 2410k ... java.lang.reflect.Method
                        28386 ... 2328k ... EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap (CL #2)
                        28439 ... 2227k ... java.util.WeakHashMap$Entry[]
                        140604 .. 2196k ... java.util.HashSet
                        56231 ... 1976k ... EDU.oswego.cs.dl.util.concurrent.LinkedQueue (CL #2)
                        27876 ... 1932k ... org.jboss.remoting.transport.local.LocalClientInvoker (CL #4)
                        82629 ... 1901k ... nu.xom.Node[] (CL #78)
                        28439 ... 1777k ... java.util.WeakHashMap
                        28210 ... 1763k ... java.util.Properties
                        28498 ... 1669k ... java.util.WeakHashMap$Entry
                        28104 ... 1564k ... org.jboss.aop.ClassInstanceAdvisor (CL #109)
                        27876 ... 1524k ... org.jboss.remoting.InvocationRequest (CL #4)
                        27977 ... 1420k ... org.jboss.util.LRUCachePolicy$LRUList (CL #2)
                        86154 ... 1346k ... java.util.HashMap$EntrySet
                        56250 ... 1318k ... EDU.oswego.cs.dl.util.concurrent.LinkedNode (CL #2)
                        28104 ... 1317k ... org.jboss.aop.InstanceAdvisorDelegate (CL #109)
                        11647 ... 1296k ... org.jboss.mx.server.InvocationContext (CL #2)
                        28029 ... 1122k ... EDU.oswego.cs.dl.util.concurrent.QueuedExecutor (CL #2)
                        27875 ... 1116k ... org.jboss.remoting.transport.socket.LRUPool (CL #4)
                        55778 ... 1089k ... org.jboss.remoting.Home (CL #4)
                        27876 ... 1088k ... org.jboss.remoting.callback.DefaultCallbackErrorHandler (CL #4)


                        Putting aside the observation that what you're doing is an anti-pattern for a minute....

                        The objects leaked are JBoss Remoting object - can you try posting in the JBoss Remoting forum please?