Starting Sun Java System Application Server 9.1 (build b41d-beta2) ...
I have a Timer Service @Timeout method firing.
[code]
@EJB(name="ejb/TaskRunnerSessionBean", beanName = "TaskRunnerSessionBean")
TaskRunnerSessionLocal tb;
@Timeout
public void jobRun(Timer timer) {
...
tb.executeSynchronousTask(context);
...
}
[/code]
Here is the "executeSynchronousTask" method.
[code]
@EJB(name = "ejb/TaskStatusSessionBean", beanName = "TaskStatusSessionBean")
TaskStatusSessionLocal tb;
@TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
public void executeSynchronousTask(TaskContext context) {
...
tb.updateStatus(request, TaskRequestStatus.STARTING);
...
}
[/code]
Finally, the "updateStatus" method.
[code]
@TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
public void updateStatus(TaskRequest request, int taskStatusId) {
...
}
[/code]
updateStatus calls Yet Another Stateless Session Bean that use an EntityManager to save data in the database, but those methods are not annotated at all, and so share the transaction that updateStatus is using.
In this specific case, when the updateStatus method returns, I get an IllegalStateException (Stack trace at the bottom).
It is apparently blowing up here, in com.sun.jts.jta.TransactionManagerImpl ("I'll take Source Code for $200, Alex"):
[code]
public void resume(Transaction suspended) throws
InvalidTransactionException, IllegalStateException, SystemException {
// thread is already associated with a transaction?
--> if (getTransaction() != null) throw new IllegalStateException();
[/code]
With FINEST logging turned on within the container, I see my three transactions being created. First for the Timer Service @Timeout call (txId = 224), next for the executeSynchronousTask (txId = 225), and finally for the updateStatus method (txId = 226).
But for some reason on the way out of updateStatus, it gets ugly.
Below is the server log file and the stack trace. Any thoughts appreciated.
[code]
--Created new J2EETransaction, txId = 224
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
In J2EETransactionManagerOpt.enlistResource, h=119
h.xares=com.sun.gjc.spi.XAResourceImpl_at_ea040e
h.alloc=com.sun.enterprise.resource.ConnectorAllocator_at_e0623f
tx=J2EETransaction: txId=224 nonXAResource=null jtsTx=null localTxStatus=0
syncs=[com.sun.ejb.containers.ContainerSynchronization_at_1b063d0]
TM: begin
TM: enlistResource
--In J2EETransaction.enlistResource, jtsTx=com.sun.jts.jta.TransactionImpl_at_7a792e4a nonXAResource=null
--In J2EETransaction.registerSynchronization, jtsTx=com.sun.jts.jta.TransactionImpl_at_7a792e4a nonXAResource=null
TM: delistResource
TM: enlistComponentResources
TM: delistResource
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=com.sun.jts.jta.TransactionImpl_at_7a792e4a nonXAResource=null
TM: suspend
--Created new J2EETransaction, txId = 225
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
--Created new J2EETransaction, txId = 226
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
SELECT JCTASKREQUESTKEY, SUCCESSITEMCOUNT, ERRORITEMCOUNT, NOTES, COMPLETEDDATE,
PRIORITY, SUBMITDATE, SCHEDULEDSTARTDATE, TOTALITEMCOUNT, HANDLE,
JCREQUESTEDBY, JCTASKREQUESTSTATUSKEY, JCTASKKEY
FROM JCTASKREQUEST WHERE (JCTASKREQUESTKEY = ?)
bind => [307]
TM: enlistComponentResources
TM: enlistComponentResources
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
SELECT SEQ1_JCTASKREQUESTEVENT.NEXTVAL FROM DUAL
TM: enlistComponentResources
In J2EETransactionManagerOpt.enlistResource, h=71
h.xares=com.sun.enterprise.resource.ConnectorXAResource_at_1f84cbc
h.alloc=com.sun.enterprise.resource.LocalTxConnectorAllocator_at_1d9dbfc
tx=J2EETransaction: txId=226 nonXAResource=null jtsTx=null localTxStatus=0
syncs=[com.sun.ejb.containers.ContainerSynchronization_at_6a347e,
oracle.toplink.essentials.transaction.JTASynchronizationListener_at_9c5a28,
com.j2.core.zuma.audit.TransactionSynchronizer_at_e301a3]
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=71
UPDATE JCTASKREQUEST SET JCTASKREQUESTSTATUSKEY = ?
WHERE (JCTASKREQUESTKEY = ?)
bind => [5, 307]
INSERT INTO JCTASKREQUESTEVENT (JCTASKREQUESTEVENTKEY, MESSAGE, OUTPUTURL,
EVENTDATE, JCTASKREQEVENTTYPEKEY, JCTASKREQUESTKEY) VALUES (?, ?, ?, ?, ?, ?)
bind => [1371, Status changed to STARTING, null, 2007-06-29 14:59:11.461, 5, 307]
--In J2EETransaction.commit, jtsTx=null nonXAResource=71
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=71
In J2EETransactionManagerOpt.enlistResource, h=124
h.xares=com.sun.messaging.jmq.jmsclient.XAResourceForMC_at_4ffeaa
h.alloc=com.sun.enterprise.resource.ConnectorAllocator_at_1c9b57e
tx=J2EETransaction: txId=225 nonXAResource=null jtsTx=null localTxStatus=0
syncs=[com.sun.ejb.containers.ContainerSynchronization_at_ac8605,
oracle.toplink.essentials.transaction.JTASynchronizationListener_at_92dfbe]
TM: begin
TM: enlistResource
--In J2EETransaction.enlistResource, jtsTx=com.sun.jts.jta.TransactionImpl_at_ebfb71ab nonXAResource=null
--In J2EETransaction.registerSynchronization, jtsTx=com.sun.jts.jta.TransactionImpl_at_ebfb71ab nonXAResource=null
TM: delistResource
--In J2EETransaction.delistResource, jtsTx=com.sun.jts.jta.TransactionImpl_at_ebfb71ab nonXAResource=null
TM: delistResource
TM: resume
EJB5018: An exception was thrown during an ejb invocation on [TaskStatusSessionBean]
javax.ejb.EJBException: nested exception is: java.lang.IllegalStateException
java.lang.IllegalStateException
at com.sun.jts.jta.TransactionManagerImpl.resume(TransactionManagerImpl.java:443)
at com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.resume(J2EETransactionManagerImpl.java:1101)
at com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.resume(J2EETransactionManagerOpt.java:515)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3533)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1305)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1267)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:192)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:114)
at $Proxy197.updateStatus(Unknown Source)
at com.j2.core.zuma.ejb.TaskRunnerSessionBean.executeSynchronousTask(TaskRunnerSessionBean.java:81)
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 com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1055)
at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:163)
at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2846)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3930)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:184)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:114)
at $Proxy199.executeSynchronousTask(Unknown Source)
at com.j2.core.zuma.ejb.JobSessionBean.jobRun(JobSessionBean.java:71)
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 com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1055)
at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:163)
at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2846)
at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:2775)
at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1388)
at com.sun.ejb.containers.EJBTimerService.access$100(EJBTimerService.java:86)
at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1939)
at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.service(EJBTimerService.java:1935)
at com.sun.ejb.containers.util.WorkAdapter.doWork(WorkAdapter.java:62)
at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:502)
javax.ejb.EJBException: nested exception is: java.lang.IllegalStateException
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1312)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1267)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:192)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:114)
at $Proxy197.updateStatus(Unknown Source)
at com.j2.core.zuma.ejb.TaskRunnerSessionBean.executeSynchronousTask(TaskRunnerSessionBean.java:81)
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 com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1055)
at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:163)
at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2846)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3930)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:184)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:114)
at $Proxy199.executeSynchronousTask(Unknown Source)
at com.j2.core.zuma.ejb.JobSessionBean.jobRun(JobSessionBean.java:71)
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 com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1055)
at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:163)
at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2846)
at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:2775)
at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1388)
at com.sun.ejb.containers.EJBTimerService.access$100(EJBTimerService.java:86)
at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1939)
at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.service(EJBTimerService.java:1935)
at com.sun.ejb.containers.util.WorkAdapter.doWork(WorkAdapter.java:62)
at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:502)
[/code]
[Message sent by forum member 'whartung' (whartung)]
http://forums.java.net/jive/thread.jspa?messageID=224773