-
1. Re: Bean Managed transaction, commit issue is getting delayed
andey Jan 17, 2017 6:03 AM (in response to manu29585)Hi
The message shows that you do not have an active transaction while you are trying to remove content from cache. The transaction associated with current thread has already been committed.
The transaction associated with the current thread has already been committed when the application is trying to make the call to JBoss Cache, therefore it is unable to join the transaction.
The issue is normally caused by a transaction reaching it's timeout value. So you may be increase the tx timeout.
When the transaction times out and is aborted by the transaction reaper, it is the responsibility of the application to diss-associate the transaction from the thread. You are trying to do that with the session.getTransaction().rollback().
This happens because the afterTransactionCompletion callback during the Transaction Reapers cancellation process sets the hibernate transaction in the JDBCContext to null. So in the catch block, when you try and get a transaction again, the JDBCContext has none so creates a new one that has not started
So it may be that the application logic is correctly handling the scenario in this case
-
2. Re: Bean Managed transaction, commit issue is getting delayed
manu29585 Jan 17, 2017 8:17 AM (in response to andey)Thanks Anup for the response. Pls check my response below.
The message shows that you do not have an active transaction while you are trying to remove content from cache. The transaction associated with current thread has already been committed.
--> This is not the case. Because, as I said earlier, within the transaction, thread which is responsible to commit the transaction itself has not executed the commit and its blocked. What are the possibilities that this thread can be blocked inspite of completing all the statement execution is the question that I've.
Increasing the timeout will actually cause all the other client application to hang for more time.
-
3. Re: Bean Managed transaction, commit issue is getting delayed
andey Jan 17, 2017 9:04 AM (in response to manu29585)Hi,
Attach full server.log file showing the issue in full stack trace?
-
4. Re: Bean Managed transaction, commit issue is getting delayed
manu29585 Jan 18, 2017 11:14 PM (in response to andey)Due to data constraints, i'm unable to upload complete log.
But, I'm mentioning key statements and sequence of events:
We import a message from external system:
2015-12-22 15:17:11,858 INFO [XMLImporter] [EventId: ] [pool-69-thread-26] ['openlink.import.receivedMsg']: The OL message has been received
2015-12-22 15:17:11,859 INFO [XMLImporter] [EventId: ] [pool-69-thread-26] ['openlink.import.completeMsg']: The imported message is :
<message>
<type>import</type>
<event>updatevisit</event>
<messageid>201512221517085468.0</messageid>
<patient>
...
...
...
</patient>
</message>
Then, as you can observe, processing of this message has been started by pool-69-thread-26.
2015-12-22 15:17:11,861 DEBUG [SASFacadeBean] [EventId: ] [pool-69-thread-26] UPDATE_VISIT
2015-12-22 15:17:11,862 DEBUG [CommSubBean] [EventId: ] [pool-69-thread-26] updateVisit()
2015-12-22 15:17:11,862 DEBUG [BeanUtils] [EventId: ] [pool-69-thread-26] beginTx
2015-12-22 15:17:11,862 DEBUG [BeanUtils] [EventId: ] [pool-69-thread-26] getTx
2015-12-22 15:17:11,862 DEBUG [BeanUtils] [EventId: ] [pool-69-thread-26] status: STATUS_ACTIVE
2015-12-22 15:17:11,862 DEBUG [SASConnection] [EventId: ] [pool-69-thread-26] ['dao.connectionInit']: SASConnection init with db SybaseDB
2015-12-22 15:17:11,863 DEBUG [SASConnection] [EventId: ] [pool-69-thread-26] ['dao.currentTransIL']: Current TransactionIsolation level: 2
2015-12-22 15:17:11,863 DEBUG [SASConnection] [EventId: ] [pool-69-thread-26] ['dao.currentAutocommit']: Current Autocommit: false
2015-12-22 15:17:11,864 DEBUG [DAOOpenAspect] [EventId: ] [pool-69-thread-26] DAO opened!
Transaction has been started from EJB.
2015-12-22 15:17:11,865 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] SQL query: SELECT DISTINCT patient.orig_pat_name AS "patient.orig_pat_name",patient.pat_ckey AS "PatCKey",patient.pat_status AS "patient.pat_status" FROM patient WHERE (patient.ris_pat_id='abcd1234' AND patient.orig_pat_name='Test123_Test23')
2015-12-22 15:17:11,866 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] ['dao.rowsProcessed']: 1 rows processed
Some of the select query is successfully processed. Also, as shown below, there is an update statement which is run successfully:
2015-12-22 15:17:11,877 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] SQL : UPDATE patient SET blavbla='blabla' WHERE patient.pat_ckey=43490
2015-12-22 15:17:11,880 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] ['dao.rowsUpdated']: 1 rows were updated.
Then as last statement within this transaction, a select query is executed:
2015-12-22 15:17:11,903 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] SQL query: SELECT test_pacs.long_descr FROM test_pacs WHERE test_pacs.long_descr NOT LIKE '#%'
2015-12-22 15:17:11,904 DEBUG [DBBaseDAO] [EventId: ] [pool-69-thread-26] ['dao.rowsProcessed']: 1 rows processed
this statement execution was completed at 15:17:11,904
And as immediate next step, commit is to be issued and we could see that, it has been done only after 16 minutes and hence transaction is timed out. Exact problem is this. Unless this transaction is committed, all the locks held by this transaction will not be release thereby causing other client applications to hang.
2015-12-22 15:33:15,501 DEBUG [BeanUtils] [EventId: ] [pool-69-thread-26] commitTx
2015-12-22 15:33:15,502 ERROR [BeanUtils] [EventId: ] [pool-69-thread-26] commitTx() failedARJUNA-16063 The transaction is not active!
2015-12-22 15:33:15,503 DEBUG [BeanUtils] [EventId: ] [pool-69-thread-26] rollbackTx
2015-12-22 15:33:15,503 ERROR [BeanUtils] [EventId: ] [pool-69-thread-26] rollbackTx() java.lang.IllegalStateException - BaseTransaction.rollback - ARJUNA-16074 no transaction!
I'm unable to interpret as to why this transaction was hanging and commit was not issued. Had it been the case that, commit was issued and then if it was taking time, it could have been a database lock which is causing this. But, here, commit statement itself is not getting executed for 16 min.
I've also enabled transaction logs to be enabled on the production system. As and when I get this information, I can share that.
Any help is greatly appreciated.
Rgds
Manohar
-
5. Re: Bean Managed transaction, commit issue is getting delayed
andey Jan 19, 2017 4:59 AM (in response to manu29585)It seems you have long running transactions which is being time-out.
"The transaction is not active!" are caused by a transaction timeout. When a transaction times out the transaction manager rolls it back asynchronously and then when a component tries to access the transaction again (e.g. to commit it or roll it back) it won't be able to according to the JTA spec.
The default transaction timeout has been defined under "default-timeout" attribute at "transactions" subsystem in the application server configuration.
- The default is 300 seconds / 5 minutes
- You may modify the value to increase the default transaction timeout
- You may set the value to 0 to disable the transaction reaper / transaction timeout
- The application server VM must be restarted for the default-timeout change to be applied
~~~
<subsystem xmlns="urn:jboss:domain:transactions:1.4">
...(snip)...
<coordinator-environment default-timeout="300"/> <!-- HERE -->
</subsystem>
~~~
It looks to me like your it is taking longer than 5 minutes to process the message therefore its transaction is timing out.
I would recommend you to increase the transaction timeout to a higher figure to avoid this situation. It would be good if you could refactor the application code to reduce the time taken to complete a transaction. So it may be that the application logic is correctly handling the scenario in this case