I'm having an issue with deadlock in my DB.
I have 3 Session Beans name Job, Run, and Status
Job is an EJBTimer bean, and has an @Timeout method.
The @Timeout method calls a method on the Run SessionBean.
The method on the Run SessionBean is annotated with @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW).
I do this because I've found that when using the JPA, if I encounter any problems, the entire transaction is rolled back, including the transaction that consumes the Timer, and I want the timer consumed "no matter what".
Anyway, Run executes some code, and it makes calles to the Status SessionBean, and it's methods are ALSO annotated with @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW).
These are annotated such because I want each update to be reflected in the DB immediately, and not have to wait for the calling transaction to commit.
So.
The problem I'm having is that Run call's Status to update a row, and then calls Status later to update the row again.
But when it tries to update the row a second time, it's blocked. Apparently because the first update hasn't committed yet (and there's no reason for it to not have committed).
I've stepped through the code in a debugger, and when I called the Status update method the first time, I then went over to a SQL tool and tried to do an update on the same row as the code, and the SQL tool was blocked by the lock on the row -- telling me that in fact, my "Requires new" transaction wasn't committing.
Below I attached a log. I turned FINEST logging on the JTA layer, and I think this is the whole conversation going on.
We're using oracle.jdbc.pool.OracleDataSource for our JDBC connector, and its a simple javax.sql.DataSource, and not a javax.sql.XADataSource.
So, I have a couple questions.
One, obviously, why is my transaction not commiting when I think it should be. And how do I make it commit? What am I doing wrong here.
Two, if I have this in a Session Bean:
@TransactionAttribute(TransactionAttributeType.REQUIRES_NEW).
public void a() {
...
}
@TransactionAttribute(TransactionAttributeType.REQUIRES_NEW).
public void b() {
a();
...
}
when b() is called from a client, is a() really supposed to be in a different transaction than b()'s? If a() is called by a client, then, of course, but when it is called from within the session bean?? Really?
All of the beans involved are using the same Persistence Unit, and their EntityManagers are injected by @PersistenceContext. I assumed that they would all have the "same one" but now I'm not sure. Could this be because I'm mixing calls across beans and EntityManagers? Or are the EntityManagers all the same for all of the beans within a specific call sequence in to the container?
Thanx for slogging through this and any thoughts you can share.
This is an annotated log describing what I think is happening.
// The server is starting up, and since this is a EJBTimer task, it gets right to work.
--Created new J2EETransaction, txId = 4
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
[TopLink Config]: 2007.06.08 06:11:21.419--ServerSession(13576596)--Thread(Thread[p: thread-pool-1; w: 2,5,main])--property toplink.server.platform.class.name is deprecated, property toplink.target-server should be used instead.
topLink_version
application_server_name_and_version
dbPlaformHelper_detectedVendorPlatform
platform=>OraclePlatform
user name=> ""
connector=>JNDIConnector datasource name=>null
);|connecting
With the Partitioning, OLAP and Data Mining options;Oracle JDBC driver;10.2.0.2.0;
;|connected_user_database_driver
platform=>OraclePlatform
user name=> ""
connector=>JNDIConnector datasource name=>null
);|connecting
In J2EETransactionManagerOpt.enlistResource, h=11 h.xares=com.sun.enterprise.resource.ConnectorXAResource_at_3a157e h.alloc=com.sun.enterprise.resource.LocalTxConnectorAllocator_at_1592216 tx=J2EETransaction: txId=4 nonXAResource=null jtsTx=null localTxStatus=0 syncs=[com.sun.ejb.containers.ContainerSynchronization_at_ccd725]
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=11
With the Partitioning, OLAP and Data Mining options;Oracle JDBC driver;10.2.0.2.0;
;|connected_user_database_driver
login_successful
// This is the start of the process in the Job session bean.
SELECT JCTASKREQUESTKEY, SUCCESSITEMCOUNT, ERRORITEMCOUNT, NOTES, COMPLETEDDATE, PRIORITY, SUBMITDATE, SCHEDULEDSTARTDATE, TOTALITEMCOUNT, HANDLE, JCREQUESTEDBY, JCTASKREQUESTSTATUSKEY, JCTASKKEY FROM JCTASKREQUEST WHERE (JCTASKREQUESTKEY = ?)
bind => [112]
SELECT JCUSERKEY, PRINCIPALNAME, DNDISPLAYNAME FROM JCUSER WHERE (JCUSERKEY = ?)
bind => [4]
SELECT t0.JCENTITYKEY, t0.jcentitytypekey, t0.ENTITYNAME, t0.JCLANGUAGETYPECODE, t0.JCENTITYTYPEKEY, t1.JCENTITYKEY, t1.DESCRIPTION, t1.NAME FROM JCENTITY t0, JCDEPARTMENT t1 WHERE ((t1.MANAGERUSERKEY = ?) AND ((t1.JCENTITYKEY = t0.JCENTITYKEY) AND (t0.jcentitytypekey = ?)))
bind => [4, 7]
SELECT JCTASKREQUESTSTATUSKEY, NAME, DESCRIPTION, SORTORDER FROM JCTASKREQUESTSTATUS WHERE (JCTASKREQUESTSTATUSKEY = ?)
bind => [7]
SELECT JCTASKKEY, JAVACLASSNAME, ISACTIVE, NAME, DESCRIPTION, JCSUBSOURCESYSTEMCODE FROM JCTASK WHERE (JCTASKKEY = ?)
bind => [26]
SELECT JCSUBSOURCESYSTEMCODE, SORTORDER, DESCRIPTION, NAME FROM JCSUBSOURCESYSTEM WHERE (JCSUBSOURCESYSTEMCODE = ?)
bind => [JC]
// At this point, Job is calling Run, and it's getting the info on the task it's running.
--Created new J2EETransaction, txId = 5
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
TM: enlistComponentResources
SELECT JCTASKREQEVENTTYPEKEY, NAME, DESCRIPTION, SORTORDER FROM JCTASKREQUESTEVENTTYPE WHERE (JCTASKREQEVENTTYPEKEY = ?)
bind => [5]
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
SELECT JCTASKREQUESTEVENTKEY, MESSAGE, OUTPUTURL, EVENTDATE, JCTASKREQEVENTTYPEKEY, JCTASKREQUESTKEY FROM JCTASKREQUESTEVENT WHERE (JCTASKREQUESTKEY = ?)
bind => [112]
SELECT DATEVALUE, STRINGVALUE, INTVALUE, JCTASKREQUESTKEY, JCTASKPARAMKEY FROM JCTASKREQUESTPARAM WHERE (JCTASKREQUESTKEY = ?)
bind => [112]
// At this stage, we're calling the Status bean from Run.
// We're changing the status of the task. This updates the request,
// and creates and EVENT row also.
SELECT SEQ1_JCTASKREQUESTEVENT.NEXTVAL FROM DUAL
In J2EETransactionManagerOpt.enlistResource, h=15 h.xares=com.sun.enterprise.resource.ConnectorXAResource_at_83edb3 h.alloc=com.sun.enterprise.resource.LocalTxConnectorAllocator_at_1592216 tx=J2EETransaction: txId=5 nonXAResource=null jtsTx=null localTxStatus=0 syncs=[com.sun.ejb.containers.ContainerSynchronization_at_16abd81, com.j2.core.zuma.audit.TransactionSynchronizer_at_bf7a86]
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=15
INSERT INTO JCTASKREQUESTEVENT (JCTASKREQUESTEVENTKEY, MESSAGE, OUTPUTURL, EVENTDATE, JCTASKREQEVENTTYPEKEY, JCTASKREQUESTKEY) VALUES (?, ?, ?, ?, ?, ?)
bind => [109, Status changed to RESTARTING, null, 2007-06-08 18:11:27.044, 5, 112]
--In J2EETransaction.commit, jtsTx=null nonXAResource=15
// This ^^^ commit is very interesting to me. It is a seperate
// method within the Status bean, called by the updateStatus method.
// But both method are annotated with REQUIRES_NEW. I find this
// interesting because I didn't think that the transaction
// annotation took effect from methods called within the same
// session bean. So, I'm surprised that there is a new transaction
// and a commit here, rather than having it bundled with the same
// transaction as the parent method. Maybe I'm mistaken on how
// this works.
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=15
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=11
UPDATE JCTASKREQUEST SET JCTASKREQUESTSTATUSKEY = ? WHERE (JCTASKREQUESTKEY = ?)
bind => [7, 112]
// We've exited the first call to the status bean, and now we're
// making another call in to the Status bean, again REQUIRES_NEW
// is in play on this method.
// Here is the code for this method:
// String eql = "update TaskRequest r set r.totalItemCount = :count where r.taskRequestKey = :key";
// Query q = em.createQuery(eql);
// q.setParameter("key", request.getTaskRequestKey());
// q.setParameter("count", itemCnt);
// q.executeUpdate();
// request = zb.refresh(request);
// return request;
//
// The thing to note here is that the "zb.refresh" is a call to
// YET ANOTHER session bean to reload the request. zb.refresh
// has no Transaction annotations at all in the other session bean.
UPDATE JCTASKREQUEST SET TOTALITEMCOUNT = ? WHERE (JCTASKREQUESTKEY = ?)
bind => [1, 112]
TM: enlistComponentResources
SELECT JCTASKREQUESTKEY, SUCCESSITEMCOUNT, ERRORITEMCOUNT, NOTES, COMPLETEDDATE, PRIORITY, SUBMITDATE, SCHEDULEDSTARTDATE, TOTALITEMCOUNT, HANDLE, JCREQUESTEDBY, JCTASKREQUESTSTATUSKEY, JCTASKKEY FROM JCTASKREQUEST WHERE (JCTASKREQUESTKEY = ?)
bind => [112]
--Created new J2EETransaction, txId = 6
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
SELECT JCTASKREQUESTSTATUSKEY, NAME, DESCRIPTION, SORTORDER FROM JCTASKREQUESTSTATUS WHERE (JCTASKREQUESTSTATUSKEY = ?)
bind => [2]
TM: enlistComponentResources
TM: enlistComponentResources
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=null
TM: enlistComponentResources
SELECT JCTASKREQUESTEVENTKEY, MESSAGE, OUTPUTURL, EVENTDATE, JCTASKREQEVENTTYPEKEY, JCTASKREQUESTKEY FROM JCTASKREQUESTEVENT WHERE (JCTASKREQUESTKEY = ?)
bind => [112]
// We've returned from the Status bean once again, and calling
// back in to it. Note, that we haven't committed anything yet.
// We're calling the same status update method we called before.
// Notice here how the INSERT is committed, but nothing else.
// The UPDATE is where we lock up.
SELECT SEQ1_JCTASKREQUESTEVENT.NEXTVAL FROM DUAL
In J2EETransactionManagerOpt.enlistResource, h=10 h.xares=com.sun.enterprise.resource.ConnectorXAResource_at_190f7c0 h.alloc=com.sun.enterprise.resource.LocalTxConnectorAllocator_at_1592216 tx=J2EETransaction: txId=6 nonXAResource=null jtsTx=null localTxStatus=0 syncs=[com.sun.ejb.containers.ContainerSynchronization_at_797bc6, com.j2.core.zuma.audit.TransactionSynchronizer_at_1ad3398]
--In J2EETransaction.registerSynchronization, jtsTx=null nonXAResource=10
INSERT INTO JCTASKREQUESTEVENT (JCTASKREQUESTEVENTKEY, MESSAGE, OUTPUTURL, EVENTDATE, JCTASKREQEVENTTYPEKEY, JCTASKREQUESTKEY) VALUES (?, ?, ?, ?, ?, ?)
bind => [110, Status changed to RUNNING, null, 2007-06-08 18:11:27.404, 5, 112]
--In J2EETransaction.commit, jtsTx=null nonXAResource=10
UPDATE JCTASKREQUEST SET TOTALITEMCOUNT = ?, JCTASKREQUESTSTATUSKEY = ? WHERE (JCTASKREQUESTKEY = ?)
bind => [1, 2, 112]
[Message sent by forum member 'whartung' (whartung)]
http://forums.java.net/jive/thread.jspa?messageID=221323