9:08 a.m.
[ http://jira.jboss.com/jira/browse/JBTM-226?page=comments#action_12380349 ]
Marko Kanala commented on JBTM-226:
-----------------------------------
Could this kind of a problem exist on 4.2.0-GA version ? A production environment I'm
involved with stalled mysteriously from 100% cpu usage with no clear indication for the
fault:
...
2007-10-04 03:10:15,254 DEBUG [org.jboss.ejb.StatelessSessionContainer] Useless invocation
of remove() for stateless session bean
2007-10-04 03:11:59,427 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:11:59>
2007-10-04 03:11:59,427 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:11:59,427 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:11:59,428 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:12:09,437 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:12:09>
2007-10-04 03:12:09,437 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:12:09,437 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:12:09,437 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:12:32,297 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:14:09,438 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:14:09>
2007-10-04 03:14:09,438 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:14:09,438 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:14:09,439 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:14:19,448 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:14:19>
2007-10-04 03:14:19,448 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:14:19,448 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:14:19,448 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:15:02,308 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:16:19,449 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:16:19>
2007-10-04 03:16:19,449 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:16:19,450 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:16:19,450 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:16:29,459 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:16:29>
2007-10-04 03:16:29,459 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:16:29,459 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:16:29,460 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:17:32,320 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:18:29,460 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:18:29>
2007-10-04 03:18:29,461 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:18:29,461 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:18:29,461 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:18:39,470 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:18:39>
2007-10-04 03:18:39,470 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:18:39,471 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:18:39,471 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:20:02,491 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:20:39,472 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:20:39>
2007-10-04 03:20:39,472 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:20:39,472 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:20:39,473 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:20:49,482 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:20:49>
2007-10-04 03:20:49,482 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:20:49,482 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:20:49,482 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:22:32,493 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:22:49,484 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:22:49>
2007-10-04 03:22:49,484 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:22:49,484 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:22:49,485 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:22:59,494 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:22:59>
2007-10-04 03:22:59,494 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:22:59,507 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:22:59,507 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:24:59,515 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:24:59>
2007-10-04 03:24:59,515 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:24:59,515 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:24:59,516 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:25:02,495 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:25:09,525 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:25:09>
2007-10-04 03:25:09,525 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:25:09,525 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:25:09,525 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:25:28,775 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
--- ExpiredEntryMonitor ----to, 4 loka 2007 03:25:28----
2007-10-04 03:27:09,526 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:27:09>
2007-10-04 03:27:09,526 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
2007-10-04 03:27:09,527 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
2007-10-04 03:27:09,527 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-10-04 03:27:19,536 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- second pass <to, 4 loka 2007 03:27:19>
2007-10-04 03:27:19,536 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
2007-10-04 03:27:19,536 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
2007-10-04 03:27:19,537 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
2007-10-04 03:27:32,496 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run:
IdleRemover notifying pools, interval: 150000
2007-10-04 03:29:19,537 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery
- first pass <to, 4 loka 2007 03:29:19>
...
The jboss had to be restarted to get rid of the 100% cpu usage.
Possible race condition between top-down and bottom-up recovery
---------------------------------------------------------------
Key: JBTM-226
URL: http://jira.jboss.com/jira/browse/JBTM-226
Project: JBoss Transaction Manager
Issue Type: Bug
Security Level: Public(Everyone can see)
Components: JTA Implementation
Affects Versions: 4.2.3.SP4
Environment: Mac OS X, JDK 1.4.2.
Reporter: Mark Little
Assigned To: Mark Little
Priority: Critical
Fix For: 4.6
In local JTA recovery for non-serializable XAResources, the XAResourceRecovery
implementation is needed to obtain a new XAResource. If a new resource isn't obtained
(because the XAResourceRecovery instances haven't all been triggered yet), top-down
recovery retries on subsequent recovery sweeps. Meanwhile, bottom up recovery can kick in
and use an XAResource from a XAResourceRecovery that is now available and fail to locate
any information on the transaction that will drive it top-down. Upon failing to find the
transaction, it uses presumed abort and rolls back the instance, when in fact it should
wait and commit it. But it doesn't do that until several phases have passed, and in
which case most of the time top-down recovery will have re-run, found the XAResource and
committed the transaction.
I'm fairly sure this is a race condition and does exist, but am still checking. Work
around exists at the moment though.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira