Support Migration Notice: To update migrated JIRA cases click here to open a new case use www.vmware.com/go/sr | vFabric Hyperic 5.7.0 is Now Available

Hyperic HQ

RollbackException and java.lang.IllegalStateException in server log

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Cannot Reproduce
  • Affects Version/s: 4.2.0
  • Fix Version/s: None
  • Component/s: Alerts
  • Environment:
    Release 4.2.0-EE build 1171,Platform:WindowsXPSP2,DB:Built-in

Description

I see the following error in my server log

This happen today when I login to my computer in the morning ,HQ server and agent where running since yesterday

2009-08-05 09:15:32,656 INFO [Scheduler-6] [org.hyperic.hq.measurement.DataPurgeJob@115] Data compression starting at 8/5/09 9:15:32 AM
2009-08-05 09:15:32,625 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.hyperic.hq.bizapp.server.action.email.EmailFilter@295] Error sending email: [HQ] !! - 3-Multicondition Alert nbhayani-pc

2009-08-05 09:15:35,406 WARN [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.hyperic.hq.application.HQApp@324] Method ran a long time.
Class: org.hyperic.hq.bizapp.shared.EmailManagerLocal
Method: sendAlert
RunTime: 36904485

2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.hyperic.hq.events.server.session.ClassicEscalatableCreator@179] Error registering to send an AlertFiredEvent on transaction commit. The alert will be fired, but the event will not be sent. This could cause a future recovery alert not to fire.
org.hibernate.TransactionException: Could not register synchronization
at org.hibernate.transaction.CMTTransaction.registerSynchronization(CMTTransaction.java:159)
at org.hyperic.hq.application.HQApp.scheduleCommitCallback(HQApp.java:705)
at org.hyperic.hq.application.HQApp.addTransactionListener(HQApp.java:731)
at org.hyperic.hq.events.server.session.ClassicEscalatableCreator.registerAlertFiredEvent(ClassicEscalatableCreator.java:168)
at org.hyperic.hq.events.server.session.ClassicEscalatableCreator.createEscalatable(ClassicEscalatableCreator.java:97)
at org.hyperic.hq.events.server.session.AlertManagerEJBImpl.fireAlert(AlertManagerEJBImpl.java:331)
at org.hyperic.hq.events.server.session.AlertManagerEJBImpl.handleAlertConditionsSatisfiedEvents(AlertManagerEJBImpl.java:284)
at sun.reflect.GeneratedMethodAccessor1360.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:526)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:598)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:526)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:598)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy244.handleAlertConditionsSatisfiedEvents(Unknown Source)
at org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener.processEvents(AlertConditionsSatisfiedListener.java:16)
at org.hyperic.hq.zevents.TimingListenerWrapper.processEvents(TimingListenerWrapper.java:44)
at org.hyperic.hq.zevents.BufferedListener$BufferedEventRunnable.run(BufferedListener.java:63)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.syncwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.syncwhenaborted] Can't register synchronization because the transaction is in aborted state
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronizationImple(TransactionImple.java:465)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronization(TransactionImple.java:441)
at org.hibernate.transaction.CMTTransaction.registerSynchronization(CMTTransaction.java:156)
... 37 more
2009-08-05 09:15:35,406 WARN [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.hyperic.hq.application.HQApp@324] Method ran a long time.
Class: org.hyperic.hq.events.shared.AlertManagerLocal
Method: handleAlertConditionsSatisfiedEvents
RunTime: 36904563

2009-08-05 09:15:32,546 DEBUG [Galert Event Listener1] [org.hyperic.hq.galerts.processor.MemGalertDef.Fired@153] Alert def [Group Alert-CPU- 780257] with id=10002 firing
2009-08-05 09:15:32,546 INFO [Scheduler-3] [org.hyperic.hq.auth.shared.SessionManager@49] cleaning up expired sessions
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.jboss.ejb.plugins.LogInterceptor@308] TransactionRolledbackLocalException in method: public abstract void org.hyperic.hq.events.shared.AlertManagerLocal.handleAlertConditionsSatisfiedEvents(java.util.Collection), causedBy:
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:361)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:526)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:598)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy244.handleAlertConditionsSatisfiedEvents(Unknown Source)
at org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener.processEvents(AlertConditionsSatisfiedListener.java:16)
at org.hyperic.hq.zevents.TimingListenerWrapper.processEvents(TimingListenerWrapper.java:44)
at org.hyperic.hq.zevents.BufferedListener$BufferedEventRunnable.run(BufferedListener.java:63)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2009-08-05 09:15:35,406 WARN [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [org.hyperic.util.thread.LoggingThreadGroup@45] ThreadGroup[ZEventProcessor]: Unhandled exception
org.jboss.tm.JBossTransactionRolledbackLocalException: - nested throwable: (java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!)
at org.jboss.ejb.plugins.TxInterceptorCMT.throwJBossException(TxInterceptorCMT.java:570)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:522)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:361)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:526)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:598)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy244.handleAlertConditionsSatisfiedEvents(Unknown Source)
at org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener.processEvents(AlertConditionsSatisfiedListener.java:16)
at org.hyperic.hq.zevents.TimingListenerWrapper.processEvents(TimingListenerWrapper.java:44)
at org.hyperic.hq.zevents.BufferedListener$BufferedEventRunnable.run(BufferedListener.java:63)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
... 19 more
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] Exception in thread "org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882"
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] org.jboss.tm.JBossTransactionRolledbackLocalException: - nested throwable: (java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.jboss.ejb.plugins.TxInterceptorCMT.throwJBossException(TxInterceptorCMT.java:570)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:522)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:361)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:526)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:598)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
2009-08-05 09:15:35,406 ERROR [org.hyperic.hq.events.server.session.AlertConditionsSatisfiedListener@4bec882] [STDERR@152] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
2009-08-05 09:15:35,406 INFO [Scheduler-6] [org.hyperic.hq.measurement.DataPurgeJob@167] Performing database analyze
2009-08-05 09:15:35,406 INFO [Thread-10] [org.hyperic.hq.common.DiagnosticThread@115] [ehcache]

  1. server.08-05.log
    07/Aug/09 1:03 PM
    390 kB
    Nipuna Bhayani
  2. server.08-06.log
    07/Aug/09 1:04 PM
    445 kB
    Nipuna Bhayani
  3. server.log-08-05.txt
    05/Aug/09 4:53 PM
    335 kB
    Nipuna Bhayani

Activity

Hide
Kashyap Parikh added a comment -

Based on the Mathod ran long timing ->

Class: org.hyperic.hq.events.shared.AlertManagerLocal
Method: handleAlertConditionsSatisfiedEvents
RunTime: 36904563

which it 10.5 hours I am assuming this has some connection to your laptop (running HQ server and DB) going in standby yesterday evening and then coming back to active mode today morning. But this thing has worked in past so would be nice to find out what happened.

Show
Kashyap Parikh added a comment - Based on the Mathod ran long timing -> Class: org.hyperic.hq.events.shared.AlertManagerLocal Method: handleAlertConditionsSatisfiedEvents RunTime: 36904563 which it 10.5 hours I am assuming this has some connection to your laptop (running HQ server and DB) going in standby yesterday evening and then coming back to active mode today morning. But this thing has worked in past so would be nice to find out what happened.
Hide
Jennifer Hickey added a comment -

The piece of code that attempts to register for the transaction callback is new, which explains the appearance of this exception in the log (it shouldn't have actually caused any issues in the running system - it simply can't send an AlertFiredEvent on transaction commit, which looks like it wasn't going to happen anyway). I assume the transaction aborted after a certain timeout on open connection (seems reasonable), but just to confirm would you normally expect the operation to complete successfully after a 10.5 hour pause?

Show
Jennifer Hickey added a comment - The piece of code that attempts to register for the transaction callback is new, which explains the appearance of this exception in the log (it shouldn't have actually caused any issues in the running system - it simply can't send an AlertFiredEvent on transaction commit, which looks like it wasn't going to happen anyway). I assume the transaction aborted after a certain timeout on open connection (seems reasonable), but just to confirm would you normally expect the operation to complete successfully after a 10.5 hour pause?
Hide
Jennifer Hickey added a comment -

Confirmed that an abort after 15 mins is expected, thus the proper solution here is to handle registration of transaction synchronizations more gracefully, so we aren't attempting to register a post-commit listener on a transaction that is no longer active.

Show
Jennifer Hickey added a comment - Confirmed that an abort after 15 mins is expected, thus the proper solution here is to handle registration of transaction synchronizations more gracefully, so we aren't attempting to register a post-commit listener on a transaction that is no longer active.
Hide
David Wiener added a comment -

Closed due to being outdated

Show
David Wiener added a comment - Closed due to being outdated

People

Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved:
    Last comment:
    1 year, 36 weeks, 2 days ago