[marklittle]

Doesn't help. I would expect to see something about "BaseTransaction.setRollbackOnly" in the debug, but I don't.

[icordoba]

2007-11-27 12:51:11,821 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::finalize()
2007-11-27 12:51:11,820 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,825 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@1308faf )
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3c244179:b941:474afb45:9045, 1)
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 30, 28, 1--3c244179:b941:474afb45:903f-3c244179:b941:474afb45:9044 > )
2007-11-27 12:51:11,826 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3c244179:b941:474afb45:9045
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,827 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.commit
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commitAndDisassociate
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id -3c244179:b941:474afb45:903f
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::onePhaseCommit() for action-id -3c244179:b941:474afb45:903f
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.topLevelOnePhaseCommit for < 131075, 30, 28, 1--3c244179:b941:474afb45:903f-3c244179:b941:474afb45:9044 >
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-11-27 12:51:11,828 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action -3c244179:b941:474afb45:903f removing TSThread:c
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action -3c244179:b941:474afb45:903f removing TSThread:c result = true
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::remove ( BasicAction: -3c244179:b941:474afb45:903f status: ActionStatus.COMMITTED )
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.resume
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action -3c244179:b941:474afb45:611e adding Thread[ajp-127.0.0.1-8010-6,5,jboss]
2007-11-27 12:51:11,829 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action -3c244179:b941:474afb45:611e adding Thread[ajp-127.0.0.1-8010-6,5,jboss] result = false
2007-11-27 12:51:11,829 DEBUG [com.servengine.struts.AuthorizeAction] icordoba@mime directly authorized to com.servengine.filepublisher.AdminActions
2007-11-27 12:51:11,830 WARN [org.apache.commons.validator.ValidatorResources] Form 'files' not found for locale 'en_US'
2007-11-27 12:51:11,830 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
2007-11-27 12:51:11,831 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: null
2007-11-27 12:51:11,831 ERROR [org.hibernate.util.JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:b941:474afb45:611e status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:b941:474afb45:611e status: ActionStatus.ABORT_ONLY >)
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
2007-11-27 12:51:11,832 ERROR [com.servengine.filepublisher.Actions] org.hibernate.exception.GenericJDBCException: Cannot open connection
javax.ejb.EJBTransactionRolledbackException: org.hibernate.exception.GenericJDBCException: Cannot open connection
 at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130)
 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
 at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240)
 at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210)
 at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84)
 at $Proxy850.getRootCategories(Unknown Source)
 at com.servengine.filepublisher.Actions.categories(Actions.java:73)
 at com.servengine.filepublisher.Actions.unspecified(Actions.java:62)
 at sun.reflect.GeneratedMethodAccessor686.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.apache.struts.actions.ActionDispatcher.dispatchMethod(ActionDispatcher.java:362)
 at org.apache.struts.actions.ActionDispatcher.unspecified(ActionDispatcher.java:261)
 at org.apache.struts.actions.ActionDispatcher.dispatchMethod(ActionDispatcher.java:317)
 at org.apache.struts.actions.ActionDispatcher.execute(ActionDispatcher.java:223)
 at com.servengine.struts.ClientAction.execute(ClientAction.java:106)
 at org.apache.struts.chain.commands.servlet.ExecuteAction.execute(ExecuteAction.java:58)
 at org.apache.struts.chain.commands.AbstractExecuteAction.execute(AbstractExecuteAction.java:67)
 at org.apache.struts.chain.commands.ActionCommandBase.execute(ActionCommandBase.java:51)
 at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
 at org.apache.commons.chain.generic.LookupCommand.execute(LookupCommand.java:304)
 at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
 at org.apache.struts.chain.ComposableRequestProcessor.process(ComposableRequestProcessor.java:283)
 at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1913)
 at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:449)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at com.servengine.struts.UTF8Filter.doFilter(UTF8Filter.java:16)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179)
 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
 at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
 at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366)
 at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
 at java.lang.Thread.run(Thread.java:595)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection
 at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:629)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:73)
 at com.servengine.filepublisher.FilePublisherManagerBean.getRootCategories(FilePublisherManagerBean.java:515)
 at sun.reflect.GeneratedMethodAccessor428.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
 at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
 at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
 ... 58 more
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
 at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
 at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
 at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
 at org.hibernate.loader.Loader.doQuery(Loader.java:673)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
 at org.hibernate.loader.Loader.doList(Loader.java:2220)
 at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104)
 at org.hibernate.loader.Loader.list(Loader.java:2099)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
 ... 71 more

[icordoba]

Thanks Mark,
the whole stacktrace didn't fit in the message. Just noticed. here is the rest of it.
Thanks again,
Ignacio

[icordoba]

Just to add some more info:
- I get none of these exceptions when testing on my MacOS Intel box. Just when moving into Linux I get the errors. Same JBoss version, same MySQL version (not same JVM, obviously)
- Marking all EJB methods as RequiresNew stops this happening, but is not the sollution (already tried) as I cannot then get any Hibernate EJB3 entities out of the scope of the entity into Struts actions (I do this some times to operate with the entity inside a UserTransaction in the Struts Action.) UserTransaction is parked, a new Transaction is created in the EJB container and when EJB method returns the entity, I get an exception accessing relations as the session is closed because of the transaction change... anyway, cannot solve it this way.

thanks again for any help,
Ignacio

[marklittle]

I'm not going to cut-and-paste the entire stack trace again, but you should be able to find the relevant pieces to track it down now:

2007-11-27 12:51:11,831 ERROR [org.hibernate.util.JDBCExceptionReporter] Transaction is not active:
tx=TransactionImple < ac, BasicAction: -3c244179:b941:474afb45:611e status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionIm
ple < ac, BasicAction: -3c244179:b941:474afb45:611e status: ActionStatus.ABORT_ONLY >)
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
2007-11-27 12:51:11,831 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
2007-11-27 12:51:11,832 ERROR [com.servengine.filepublisher.Actions] org.hibernate.exception.Generic
JDBCException: Cannot open connection
javax.ejb.EJBTransactionRolledbackException: org.hibernate.exception.GenericJDBCException: Cannot op
en connection
 at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130)
 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)

is the start, and this seems to be triggered by:

Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Can
not open connection
 at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.
java:629)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:73)
 at com.servengine.filepublisher.FilePublisherManagerBean.getRootCategories(FilePublisherManagerBean
.java:515)
 at sun.reflect.GeneratedMethodAccessor428.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

So Hibernate is setting the transaction to rollback only. This could be a MySQL issue: we've seen issues in other projects with MySQL running on Linux producing failures that do not show up on Windows or other OS-es. Maybe you can shift to a different database?

[icordoba]

Thanks a lot for your help. I had the opposite idea... that JBoss was invoking Hibernate with a expired transaction (or whatever).
I've been trying with MySQL 4 and 5 and with LOCAL-TX and XA JDBC drivers. I'll try with beta version of MySQL and will search any alternative JDBC drivers. I cannot switch to a different database at this moment.
Anyway, I found a very similar problem on a Hibernate user, but using Postgres (!!)
http://forum.hibernate.org/viewtopic.php?p=2369722&sid=e0544556319df31ca839a35cbceff39e

Thanks,
Ignacio

[icordoba]

Hi again everybody...
before migrating from Linux to other O.S. MySQL, I desperately attach Hibernate logs in case anyone can give me any directions.
Thanks,
Ignacio

2007-11-28 03:24:44,238 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4899703538638848
2007-11-28 03:24:44,238 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2007-11-28 03:24:44,238 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2007-11-28 03:24:44,238 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2007-11-28 03:24:44,238 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Transaction already joined
2007-11-28 03:24:44,238 DEBUG [org.hibernate.loader.Loader] loading entity: [com.servengine.portal.Component#com.servengine.filepublisher.AdminActions]
2007-11-28 03:24:44,239 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
2007-11-28 03:24:44,239 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2007-11-28 03:24:44,239 DEBUG [org.hibernate.SQL] select component0_.className as className244_0_, component0_.admin as admin244_0_, component0_.guest as guest244_0_ from Component component0_ where component0_.className=?
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2007-11-28 03:24:44,240 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.servengine.portal.Component#com.servengine.filepublisher.AdminActions]
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1) (open ResultSets: 0, globally: 0)]
2007-11-28 03:24:44,240 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.servengine.portal.Component#com.servengine.filepublisher.AdminActions]
2007-11-28 03:24:44,240 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.servengine.portal.Component#com.servengine.filepublisher.AdminActions]
2007-11-28 03:24:44,240 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2007-11-28 03:24:44,240 DEBUG [org.hibernate.loader.Loader] done entity load
2007-11-28 03:24:44,240 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
2007-11-28 03:24:44,240 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
2007-11-28 03:24:44,240 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
2007-11-28 03:24:44,240 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2007-11-28 03:24:44,240 DEBUG [org.hibernate.pretty.Printer] listing entities:
2007-11-28 03:24:44,240 DEBUG [org.hibernate.pretty.Printer] com.servengine.portal.Component{className=com.servengine.filepublisher.AdminActions, admin=true, guest=true}
2007-11-28 03:24:44,240 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2007-11-28 03:24:44,241 DEBUG [com.servengine.struts.AuthorizeAction] icordoba@mime directly authorized to com.servengine.filepublisher.AdminActions
2007-11-28 03:24:44,241 WARN [org.apache.commons.validator.ValidatorResources] Form 'files' not found for locale 'en_US'
2007-11-28 03:24:44,242 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4899703538655232
2007-11-28 03:24:44,242 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2007-11-28 03:24:44,242 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] No JTA transaction found
2007-11-28 03:24:44,243 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
2007-11-28 03:24:44,243 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2007-11-28 03:24:44,243 DEBUG [org.hibernate.util.JDBCExceptionReporter] Cannot open connection [???]
org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:e336:474c47b7:c758 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:e336:474c47b7:c758 status: ActionStatus.ABORT_ONLY >)
 at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
 at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
 at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
 at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
 at org.hibernate.loader.Loader.doQuery(Loader.java:673)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
 at org.hibernate.loader.Loader.doList(Loader.java:2220)
 at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104)
 at org.hibernate.loader.Loader.list(Loader.java:2099)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
 at com.servengine.filepublisher.FilePublisherManagerBean.getRootCategories(FilePublisherManagerBean.java:525)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
 at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
 at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
 at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240)
 at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210)
 at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84)
 at $Proxy929.getRootCategories(Unknown Source)
 at com.servengine.filepublisher.Actions.categories(Actions.java:73)
 at com.servengine.filepublisher.Actions.unspecified(Actions.java:62)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.apache.struts.actions.ActionDispatcher.dispatchMethod(ActionDispatcher.java:362)
 at org.apache.struts.actions.ActionDispatcher.unspecified(ActionDispatcher.java:261)
 at org.apache.struts.actions.ActionDispatcher.dispatchMethod(ActionDispatcher.java:317)
 at org.apache.struts.actions.ActionDispatcher.execute(ActionDispatcher.java:223)
 at com.servengine.struts.ClientAction.execute(ClientAction.java:106)
 at org.apache.struts.chain.commands.servlet.ExecuteAction.execute(ExecuteAction.java:58)
 at org.apache.struts.chain.commands.AbstractExecuteAction.execute(AbstractExecuteAction.java:67)
 at org.apache.struts.chain.commands.ActionCommandBase.execute(ActionCommandBase.java:51)
 at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
 at org.apache.commons.chain.generic.LookupCommand.execute(LookupCommand.java:304)
 at org.apache.commons.chain.impl.ChainBase.execute(ChainBase.java:190)
 at org.apache.struts.chain.ComposableRequestProcessor.process(ComposableRequestProcessor.java:283)
 at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1913)
 at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:449)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at com.servengine.struts.UTF8Filter.doFilter(UTF8Filter.java:16)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179)
 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
 at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
 at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366)
 at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
 at java.lang.Thread.run(Thread.java:595)
Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:e336:474c47b7:c758 status: ActionStatus.ABORT_ONLY >
 at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:304)
 at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:396)
 at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
 at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
 ... 89 more
2007-11-28 03:24:44,245 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: null
2007-11-28 03:24:44,245 ERROR [org.hibernate.util.JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:e336:474c47b7:c758 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3c244179:e336:474c47b7:c758 status: ActionStatus.ABORT_ONLY >)
2007-11-28 03:24:44,245 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] mark transaction for rollback