Help JBoss JTS OutOfMemoryError happened in PROD env.
wangliyu Aug 29, 2008 8:43 AMHi,
I'm using JBoss4.0.5 with JTS 4.2.2 in PROD env (Windows 2003sp1) , it happened twice the JTS OutOfMemoryError with XA transaction commit, here is the console log of JBoss:
2008-08-27 13:29:25,714 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.orbspecific.coordinator.generror] ArjunaTransactionImple.destroyAction caught exception: java.lang.OutOfMemoryError: unable to create new native thread 2008-08-27 13:31:50,321 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000 2008-08-27 13:36:31,512 ERROR [jacorb.poa.controller] rid: 25187826 opname: commit invocation: throwable was thrown (java.lang.OutOfMemoryError) java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:597) at org.jacorb.poa.AOM.remove(AOM.java:365) at org.jacorb.poa.POA.deactivate_object(POA.java:895) at com.arjuna.orbportability.RootOA.shutdownObject(RootOA.java:265) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.removeConnection(XAResourceRecord.java:1395) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.commit(XAResourceRecord.java:560) at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:184) at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:299) at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:593) at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:735) 2008-08-27 13:36:31,512 ERROR [jacorb.poa.controller] rid: 25187900 opname: commit invocation: throwable was thrown (java.lang.OutOfMemoryError) java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:597) at org.jacorb.poa.AOM.remove(AOM.java:365) at org.jacorb.poa.POA.deactivate_object(POA.java:895) at com.arjuna.orbportability.RootOA.shutdownObject(RootOA.java:265) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.removeConnection(XAResourceRecord.java:1395) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.commit(XAResourceRecord.java:560) at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:184) at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:299) at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:593) at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:735) 2008-08-27 13:36:31,528 WARN [jacorb.poa] POA RootPOAoid: 0B 39 29 36 15 39 05 22 11 4D 1A 0B 4D .9)6.9.".M..M cannot process request, because object is already in the deactivation process 2008-08-27 13:36:31,528 WARN [jacorb.poa.controller] rid: 25187910 opname: shouldMerge request rejected with exception: 2008-08-27 13:36:31,528 WARN [jacorb.poa] POA RootPOAoid: 0B 39 29 36 15 39 05 22 11 4D 1A 0B 4D .9)6.9.".M..M cannot process request, because object is already in the deactivation process 2008-08-27 13:36:31,528 WARN [jacorb.poa.controller] rid: 25187912 opname: shouldReplace request rejected with exception: 2008-08-27 13:36:31,528 WARN [jacorb.poa] POA RootPOAoid: 0B 39 29 36 15 39 05 22 11 4D 1A 0B 4D .9)6.9.".M..M cannot process request, because object is already in the deactivation process 2008-08-27 13:36:31,528 WARN [jacorb.poa.controller] rid: 25187914 opname: shouldAdd request rejected with exception: 2008-08-27 13:36:31,528 WARN [jacorb.poa] POA RootPOAoid: 0B 39 29 36 15 39 05 22 11 4D 1A 0B 4D .9)6.9.".M..M cannot process request, because object is already in the deactivation process 2008-08-27 13:36:31,528 WARN [jacorb.poa.controller] rid: 25187916 opname: shouldAlter request rejected with exception: 2008-08-27 13:36:31,543 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.orbspecific.coordinator.generror] ArjunaTransactionImple.destroyAction caught exception: java.lang.OutOfMemoryError: unable to create new native thread 2008-08-27 13:36:32,184 ERROR [jacorb.poa.controller] rid: 25187906 opname: commit invocation: throwable was thrown (java.lang.OutOfMemoryError) java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:597) at org.jacorb.poa.AOM.remove(AOM.java:365) at org.jacorb.poa.POA.deactivate_object(POA.java:895) at com.arjuna.orbportability.RootOA.shutdownObject(RootOA.java:265) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.removeConnection(XAResourceRecord.java:1395) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.commit(XAResourceRecord.java:560) at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:184) at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:299) at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:593) at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:735) 2008-08-27 13:36:32,294 WARN [com.arjuna.ats.jts.logging.loggerI18N] [com.arjuna.ats.internal.jts.orbspecific.coordinator.generror] ArjunaTransactionImple.destroyAction caught exception: java.lang.OutOfMemoryError: unable to create new native thread 2008-08-27 13:36:33,185 ERROR [STDERR] Exception in thread "RequestController-1" 2008-08-27 13:36:33,185 ERROR [STDERR] java.lang.OutOfMemoryError: unable to create new native thread 2008-08-27 13:36:33,185 ERROR [STDERR] at java.lang.Thread.start0(Native Method) 2008-08-27 13:36:33,185 ERROR [STDERR] at java.lang.Thread.start(Thread.java:597) 2008-08-27 13:36:33,185 ERROR [STDERR] at org.jacorb.poa.RPPoolManager.addProcessor(RPPoolManager.java:99) 2008-08-27 13:36:33,185 ERROR [STDERR] at org.jacorb.poa.RPPoolManager.getProcessor(RPPoolManager.java:181) 2008-08-27 13:36:33,185 ERROR [STDERR] at org.jacorb.poa.RequestController.processRequest(RequestController.java:382) 2008-08-27 13:36:33,185 ERROR [STDERR] at org.jacorb.poa.RequestController.run(RequestController.java:479)
I killed the JBoss session, the JVM create the memory report in the error log file:
Other Threads: =>0x2bd6e000 VMThread [stack: 0x2c1d0000,0x2c220000] [id=7364] 0x2c00dc00 WatcherThread [stack: 0x2c450000,0x2c4a0000] [id=11848] VM state:at safepoint (normal execution) VM Mutex/Monitor currently owned by a thread: ([mutex/lock_event]) [0x00285a60/0x00000710] Threads_lock - owner thread: 0x2bd6e000 [0x00285c00/0x000006d0] Heap_lock - owner thread: 0x45c2a400 Heap PSYoungGen total 23872K, used 96K [0x280f0000, 0x29d60000, 0x2b9d0000) eden space 23744K, 0% used [0x280f0000,0x280f0000,0x29820000) from space 128K, 75% used [0x29820000,0x29838000,0x29840000) to space 2816K, 0% used [0x29aa0000,0x29aa0000,0x29d60000) PSOldGen total 233024K, used 54209K [0x0b9d0000, 0x19d60000, 0x280f0000) object space 233024K, 23% used [0x0b9d0000,0x0eec07c8,0x19d60000) PSPermGen total 39040K, used 38937K [0x039d0000, 0x05ff0000, 0x0b9d0000) object space 39040K, 99% used [0x039d0000,0x05fd6750,0x05ff0000)
Looks the memory was good.
The XA transaction involved with both Informix DB and a MainFrame calls.
Both Informix Query timeout and Mainframe call's timeout are 60 sec.
The XA transaction reaper time is 120 sec.
And I looked the application log, all the transactions' timing are normal until suddenly it stop responding.
Can anyone help or have same issue, please let me know?
Thanks,
Liyu