4 Replies Latest reply: Jul 18, 2012 7:33 AM by Jesper Pedersen RSS

    JBoss 7.1.1.Final - Local transactions - Memory Leak

    Srikrishna Kalavacharla Newbie

      We are migrating from JBoss 6.0.0.Final to JBoss 7.1.1.Final and in load environment we have noticed that even though JBoss 7.1.1.Final shows good bump from response times perspective, it is losing memory continuously and when it reaches the max available, naturally response times are tanking and so is number of requests processed per minute in a soak test.  We have used jmap + jhat combination to figure where is the memory leak and the top 10 candidates point towards com.arjuna.* package.  We are not using jta (jta=false) and another issue we have noticed is, with jta, our response times are tanking.  (Ex: if non-jta setup gives us 3 milli seconds, jta setup shows us around 300 milli seconds for our application).  Here is some data: 

       

      10 minutes into the soak test:

       

      132405 instances of class com.arjuna.ats.arjuna.coordinator.RecordList
      88300 instances of class com.arjuna.ats.arjuna.common.Uid 
      44146 instances of class com.arjuna.ats.arjuna.coordinator.ActionHierarchy 
      44146 instances of class com.arjuna.ats.arjuna.coordinator.ActionInfo 
      44146 instances of class com.arjuna.ats.arjuna.coordinator.CheckedAction 
      44146 instances of class com.arjuna.ats.internal.arjuna.common.BasicMutex 
      44146 instances of class com.arjuna.ats.internal.jta.transaction.arjunacore.AtomicAction 
      44146 instances of class com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple 
      44146 instances of class [Lcom.arjuna.ats.arjuna.coordinator.ActionInfo; 
      44135 instances of class com.arjuna.ats.internal.jta.xa.TxInfo 
      44135 instances of class com.arjuna.ats.internal.jta.xa.XID 
      44135 instances of class com.arjuna.ats.jta.xa.XidImple 
      

       

      50 minutes into the soak test: (after 40 minutes)

       

      333036 instances of class com.arjuna.ats.arjuna.coordinator.RecordList
      222074 instances of class com.arjuna.ats.arjuna.common.Uid 
      111033 instances of class com.arjuna.ats.arjuna.coordinator.ActionHierarchy 
      111033 instances of class com.arjuna.ats.arjuna.coordinator.ActionInfo 
      111033 instances of class com.arjuna.ats.arjuna.coordinator.CheckedAction 
      111033 instances of class com.arjuna.ats.internal.arjuna.common.BasicMutex 
      111033 instances of class com.arjuna.ats.internal.jta.transaction.arjunacore.AtomicAction 
      111033 instances of class com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple 
      111033 instances of class [Lcom.arjuna.ats.arjuna.coordinator.ActionInfo; 
      111012 instances of class com.arjuna.ats.internal.jta.xa.TxInfo 
      111012 instances of class com.arjuna.ats.internal.jta.xa.XID 
      111012 instances of class com.arjuna.ats.jta.xa.XidImple  
      

       

      Our datasource setup is as follows:

       

                  <subsystem xmlns="urn:jboss:domain:datasources:1.0">
                      <datasouces>
                          <datasource jta="false" jndi-name="java:jboss/datasources/ApplicationDS" pool-name="java:jboss/datasources/ApplicationDS" enabled="true" use-ccm="true">
                              <connection-url>jdbc:inetdae7a:REPLACE_WITH_IP_ADDRESS:REPLACE_WITH_PORT_NUMBER?databaseName=ApplicationDB&amp;amp;instanceName=applicationInstance&amp;amp;loginTimeout=20&amp;amp;queryTimeout=300</connection-url>
                              <driver-class>com.inet.tds.TdsDriver</driver-class>
                              <driver>Merlia-1.0.jar</driver>
                              <pool>
                                  <min-pool-size>25</min-pool-size>
                                  <max-pool-size>250</max-pool-size>
                              </pool>
                              <security>
                                  <user-name>REPLACE_WITH_USERNAME</user-name>
                                  <password>REPLACE_WITH_PASSWORD</password>
                              </security>
                              <validation>
                                  <validate-on-match>false</validate-on-match>
                                  <background-validation>false</background-validation>
                              </validation>
                              <statement>
                                  <share-prepared-statements>false</share-prepared-statements>
                              </statement>
                          </datasource>
                          <datasource jta="false" jndi-name="java:jboss/datasources/ReportingDS" pool-name="java:jboss/datasources/ReportingDS" enabled="true" use-ccm="true">
                              <connection-url>jdbc:inetdae7a:REPLACE_WITH_IP_ADDRESS:REPLACE_WITH_PORT_NUMBER?databaseName=ReportingDB&amp;amp;instanceName=reportingInstance&amp;amp;loginTimeout=20&amp;amp;queryTimeout=300</connection-url>
                              <driver-class>com.inet.tds.TdsDriver</driver-class>
                              <driver>Merlia-1.0.jar</driver>
                              <pool>
                                  <min-pool-size>25</min-pool-size>
                                  <max-pool-size>250</max-pool-size>
                              </pool>
                              <security>
                                  <user-name>REPLACE_WITH_USERNAME</user-name>
                                  <password>REPLACE_WITH_PASSWORD</password>
                              </security>
                              <validation>
                                  <validate-on-match>false</validate-on-match>
                                  <background-validation>false</background-validation>
                              </validation>
                              <statement>
                                  <share-prepared-statements>false</share-prepared-statements>
                              </statement>
                          </datasource>
                          <drivers>
                              <driver name="Merlia-1.0.jar" module="com.inet.tds">
                                  <driver-class>com.inet.tds.TdsDriver</driver-class>
                              </driver>
                          </drivers>
                      </datasources>
                  </subsystem>
      

       

      Another question we have is, even after setting jta="false", Heap Dump shows instances of "com.arjuna.ats.internal.jta.transaction.arjunacore.AtomicAction" where package name is suggesting "jta" and is confusing.  We are thinking memory leak is at transaction level, in the base api (arjuna) as there is no indication or errors in log files pointing to our code.  When we enable DEBUG on com.arjuna package we see the following debug statements logging at regular intervals:

       

      18:16:08,027 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING
      18:16:08,027 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning
      18:16:08,027 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Mon, 16 Jul 2012 18:16:08
      18:16:08,028 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass
      18:16:08,028 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
      18:16:08,028 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:08,028 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass
      18:16:08,029 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:08,029 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass
      18:16:08,030 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:18,031 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery second pass at Mon, 16 Jul 2012 18:16:18
      18:16:18,031 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass
      18:16:18,031 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:18,031 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass
      18:16:18,031 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:18,032 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass
      18:16:18,032 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed
      18:16:18,032 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of HornetQXAResourceWrapper [serverLocator=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0], discoveryGroupConfiguration=null], csf=ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0], discoveryGroupConfiguration=null], connectorConfig=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0, backupConfig=null], delegate=DelegatingSession [session=ClientSessionImpl [name=f125010a-cf9b-11e1-a943-dc6a20524153, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0], discoveryGroupConfiguration=null], connectorConfig=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0, backupConfig=null], metaData=()]@236d7300], xaRecoveryConfigs=[XARecoveryConfig [hornetQConnectionFactory=HornetQConnectionFactory [serverLocator=ServerLocatorImpl [initialConnectors=[org-hornetq-core-remoting-impl-invm-InVMConnectorFactory?server-id=0], discoveryGroupConfiguration=null], clientID=null, dupsOKBatchSize=1048576, transactionBatchSize=1048576, readOnly=fals
      e], username=null, password=null]], instance=1281715623]
      18:16:18,034 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
      18:16:18,035 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 0 Xids to recover on this pass.
      18:16:18,035 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed
      18:16:18,036 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
      18:16:18,036 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
      18:16:18,036 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off
      

       

      We have repeated the same soak test in our JBoss 6.0.0.Final environment and it shows dismal statistics for the class com.arjuna.ats.arjuna.coordinator.RecordList class as follows:

       

      10 minutes into the test - com.arjuna.ats.arjuna.coordinator.RecordList - 1009 
      50 minutes into the test - com.arjuna.ats.arjuna.coordinator.RecordList - 244
      

                                                                           

       

      This has become a blocking issue and may have to kill our migration without a good solution.  Any pointers are greatly appreciated! Thanks!  

       

      -Srikrishna Kalavacharla