2 Replies Latest reply on Aug 13, 2008 8:22 AM by j_ri

JBossAS EAP 4.3 with JBoss Transactions 4.3.0.GA JTS - Memor

j_ri Aug 13, 2008 2:32 AM

Hi,

we just migrated from JBoss 4.0.5GA with integrated JBossTS 4.2.2 (JTS) to JBossAS EAP 4.3 with JBossTS 4.3.0.GA(JTS).

Unfortunately we ran into trouble, because we seem to have some kind of memory leak.
Within a few hours the Hashtable with reaper objects uses 0.5GB of Heap wich isn't cleaned any more by the garbace collector. SO we have to restart our servers one or two times a day;-(
Unfortunately I can't attach the screenshot from the "Memory Analyzer"

The only hint we have is the follwoing in our log-file (with arjuna in debug mode):

2008-08-12 19:41:24,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:24,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:24,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562884264
2008-08-12 19:41:24,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-13,5,jboss] sleeping for 108
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562884264
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper timeout for TX -69b8f474:1199:48a19fdf:12 state RUN
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper scheduling TX for cancellation -69b8f474:1199:48a19fdf:12
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562884686
2008-08-12 19:41:24,265 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-13,5,jboss] sleeping for 421
2008-08-12 19:41:24,312 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2']Thread[Thread-14,5,jboss],
2008-08-12 19:41:24,312 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper Worker Thread[Thread-14,5,jboss] attempting to cancel -69b8f474:1199:48a19fdf:12
2008-08-12 19:41:24,312 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:12,
2008-08-12 19:41:24,390 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:717)
 at com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:91)
2008-08-12 19:41:24,390 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:12,
2008-08-12 19:41:24,390 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1']Thread[Thread-14,5,jboss],
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562884686
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper timeout for TX -69b8f474:1199:48a19fdf:14 state RUN
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper scheduling TX for cancellation -69b8f474:1199:48a19fdf:14
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562885187
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2']Thread[Thread-14,5,jboss],
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-13,5,jboss] sleeping for 500
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper Worker Thread[Thread-14,5,jboss] attempting to cancel -69b8f474:1199:48a19fdf:14
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:14,
2008-08-12 19:41:24,687 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:717)
 at com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:91)
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:14,
2008-08-12 19:41:24,687 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1']Thread[Thread-14,5,jboss],
2008-08-12 19:41:25,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:25,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:25,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562904764
2008-08-12 19:41:25,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-13,5,jboss] sleeping for 19577
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562904764
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper timeout for TX -69b8f474:1199:48a19fdf:1d state RUN
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper scheduling TX for cancellation -69b8f474:1199:48a19fdf:1d
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562904858
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_2']Thread[Thread-14,5,jboss],
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-13,5,jboss] sleeping for 93
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper Worker Thread[Thread-14,5,jboss] attempting to cancel -69b8f474:1199:48a19fdf:1d
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_8']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:1d,
2008-08-12 19:41:44,765 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.cwcommit] Failed to mark transaction as rollback only:
org.omg.CosTransactions.Unavailable: IDL:omg.org/CosTransactions/Unavailable:1.0
 at com.arjuna.ats.internal.jts.ControlWrapper.rollback_only(ControlWrapper.java:344)
 at com.arjuna.ats.internal.jts.ControlWrapper.preventCommit(ControlWrapper.java:168)
 at com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:717)
 at com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:91)
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_15']Thread[Thread-14,5,jboss], -69b8f474:1199:48a19fdf:1d,
2008-08-12 19:41:44,765 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] Can't find resource for bundle java.util.PropertyResourceBundle, key com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1: [key='com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread_1']Thread[Thread-14,5,jboss],
2008-08-12 19:41:44,858 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperThread.run ()
2008-08-12 19:41:44,858 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
2008-08-12 19:41:44,858 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing 1218562904858
2008-08-12 19:41:44,858 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper timeout for TX -69b8f474:1199:48a19fdf:1f state RUN
2008-08-12 19:41:44,858 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Reaper scheduling TX for cancellation -69b8f474:1199:48a19fdf:1f

I hoe someone can give me a hint how to solve this.

thanks
jochen

1. Re: JBossAS EAP 4.3 with JBoss Transactions 4.3.0.GA JTS - M

adinn Aug 13, 2008 4:31 AM (in response to j_ri)

I hope someone can give me a hint how to solve this.

Well, I'll try :-)

The JTS memory leak is a known problem -- see JIRA JBTM-352 (https://jira.jboss.org/jira/browse/JBTM-352).

You will note that this has been fixed in JBossTS 4.4.CR1. Unfortunately, the fix has not been back-ported to 4.3.0 because 4.3.0 is not a maintenance release. You are also unlucky because 4.4.CR1 is only useable with AS 5.0.0CR1 -- it includes changes which make it incompatible with EAP 4.3.

What I suggest you do is back patch the code in 4.3.0 yourself as detailed in the JIRA and then rebuild and reinstall 4.3.0. The changes required are not complex so it should be easy to do.

Ignore the patch files supplied by the person who opened the JIRA. Instead click on subversion commits and you will see a commit made by me which adds a new file, PseudoControlWrapper.java, and modifies an existing file, OTSManager.java. Make the same changes in your build and the problem should go away.

By the way, there is another known problem which you are suffering from (although it will not be a problem once you install the previous fix). The transaction reaper messages you are seeing when you switch on debug trace are not being formatted correctly. Also, some of them should be displayed as errors rather than debug trace. This too has been fixed recently -- see JIRA JBTM-388 (https://jira.jboss.org/jira/browse/JBTM-388).
Actions
2. Re: JBossAS EAP 4.3 with JBoss Transactions 4.3.0.GA JTS - M

j_ri Aug 13, 2008 8:22 AM (in response to j_ri)

Thank You!;-)

I just applied the patch. We gonne test it the next few days and hope to bring it to production soon.

I'll post again ... and tell the results
Actions

Go to original post