Error checking for a transaction when executing a "long" running process that should insert results from several procedure calls in a table

[gadeyne.bram]

Hi,

The code I'm executing is a fairly simple one:

insert into wodan_sofas(admissionid,periodstart,periodend, cardio, cns, coag, liver, renal, resp)
select s.admissionid, s.periodstart, s.periodend, s.cardio, s.cns, s.coag, s.liver, s.renal, s.resp
from prod_P_GeneralData gd
join pr_sofa s on gd.PatientID = s.admissionid_in
where s.calculatehour = 5;

wodan_sofas is a physical table on MySQL.

prod_P_GeneralData is also a physical table but then on a sybase database.

pr_sofa is a virtual procedure that executes several other virtual procedures and calls also several virtual views. All calls in these procedures and views are also executed against Sybase (2 different servers).

After approximately 5 minutes the process stops with an exception:

2017-03-23 14:01:17,809 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper)  ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:6ec38752:58d3c18c:8d in state  RUN

2017-03-23 14:01:17,812 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)  ARJUNA012095: Abort of action id 0:ffff7f000101:6ec38752:58d3c18c:8d invoked while multiple threads active within it.

2017-03-23 14:01:17,812 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)  ARJUNA012381: Action id 0:ffff7f000101:6ec38752:58d3c18c:8d completed with multiple threads - thread Worker7_QueryProcessorQueue503 was in progress with org.teiid.translator.jdbc.JDBCExecutionFactory.retrieveValue(JDBCExecutionFactory.java:1071)

org.teiid.translator.jdbc.sybase.BaseSybaseExecutionFactory.retrieveValue(BaseSybaseExecutionFactory.java:124)

org.teiid.translator.jdbc.JDBCQueryExecution.next(JDBCQueryExecution.java:344)

org.teiid.dqp.internal.datamgr.ConnectorWorkItem.handleBatch(ConnectorWorkItem.java:434)

org.teiid.dqp.internal.datamgr.ConnectorWorkItem.more(ConnectorWorkItem.java:237)

sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source)

sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

java.lang.reflect.Method.invoke(Method.java:498)

org.teiid.dqp.internal.datamgr.ConnectorManager$1.invoke(ConnectorManager.java:220)

com.sun.proxy.$Proxy29.more(Unknown Source)

org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTupleSource.java:309)

org.teiid.dqp.internal.process.DataTierTupleSource.nextTuple(DataTierTupleSource.java:142)

org.teiid.query.processor.relational.AccessNode.nextBatchDirect(AccessNode.java:392)

....

2017-03-23 14:01:17,812 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)  ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000101:6ec38752:58d3c18c:8d aborting with 1 threads active!

2017-03-23 14:01:17,875 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)  ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff7f000101:6ec38752:58d3c18c:8d

2017-03-23 14:01:18,002 WARN  [org.teiid.CONNECTOR] (Worker7_QueryProcessorQueue503) Lcvh/H6BFMtj Connector worker process failed for atomic-request=Lcvh/H6BFMtj.7.153.33251: org.teiid.translator.TranslatorException: TEIID11009 java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction

        at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:282)

        at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:69)

        at org.teiid.translator.ExecutionFactory.getConnection(ExecutionFactory.java:205)

        at org.teiid.dqp.internal.datamgr.ConnectorWorkItem.execute(ConnectorWorkItem.java:328)

        at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.teiid.dqp.internal.datamgr.ConnectorManager$1.invoke(ConnectorManager.java:220)

        at com.sun.proxy.$Proxy29.execute(Unknown Source)

        at org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTup

....

Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)

        at org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:66)

        at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:278)

        ... 101 more

Caused by: javax.resource.ResourceException: IJ000460: Error checking for a transaction

        at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:424)

        at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:747)

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)

        ... 103 more

Caused by: javax.resource.ResourceException: IJ000459: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff7f000101:6ec38752:58d3c18c:8d status: ActionStatus.ABORTED >

        at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:408)

        ... 105 more

2017-03-23 14:01:18,007 WARN  [org.teiid.PROCESSOR] (Worker7_QueryProcessorQueue503) Lcvh/H6BFMtj TEIID30020 Processing exception for request Lcvh/H6BFMtj.7 'TEIID30328 Unable to evaluate (SELECT v.score FROM (EXEC izisviews.pr_sofa_cardio(izisviews.pr_sofa.admissionid_in, VARIABLES.periodstart, VARIABLES.periodend)) AS v LIMIT 2): TEIID30328 Unable to evaluate (SELECT anon_grp140.agg0 AS minsapm FROM izisviews.tv_retrieve_monvals AS mv WHERE (v__10.PatientID = izisviews.pr_sofa_cardio.admissionid) AND (v__10.VariableID = 110) AND (v__10.Entertime >= izisviews.pr_sofa_cardio.periodstart) AND (v__10.Entertime <= izisviews.pr_sofa_cardio.periodend)): TEIID30504 iziswh: TEIID11009 java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction'. Originally ExpressionEvaluationException 'IJ000459: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff7f000101:6ec38752:58d3c18c:8d status: ActionStatus.ABORTED >' TxConnectionManagerImpl.java:408. Enable more detailed logging to see the entire stacktrace.

2017-03-23 14:01:18,008 WARN  [com.arjuna.ats.arjuna] (Worker7_QueryProcessorQueue503) Lcvh/H6BFMtj ARJUNA012077: Abort called on already aborted atomic action 0:ffff7f000101:6ec38752:58d3c18c:8d

The query that it says can not be evaluated is always a different one (even different procedure calls).

Does anyone know how to resolve this issue?

[gadeyne.bram]

It is probably related to this

[TEIID-4097] No active transaction found while executing long running update statement - JBoss Issue Tracker

[shawkins]

Let us know if it doesn't get resolved by increasing the timeout.

[rareddy]

XA data source connection and InnoDB on MySQL side right?

Can you see if you can set "isSameRM" to true in your XA configuration? I think that property was designed for Oracle but it may play here too. What I think happening is, there are multiple single insert statements are being issued, for whatever reason the transaction manager is complaining at the time of commit that they inserts came from different threads. Typically Teiid uses single thread and connection until the transaction is over, however depending upon how you modeled there may be second source going to the same MySQL also participating the transaction which is in conflict. You can also try increasing the transaction timeout value and see that helps.

Ramesh..

[gadeyne.bram]

Hi,

Increasing the timeout does not help in this case.

[gadeyne.bram]

Hi Ramesh,

MySQL indeed uses innodb and both datasources are xa datasources.

I support that you propose to set the property on the MySQL datasource? If I look at the properties that can be set on a MySQL xa datasource then I see isSameRM is not one of them. Or is this not a datasource property?

The same happens when I try to insert the values in an in memory table so I'm not sure this is related to MySQL at all.

[gadeyne.bram]

I found a workaround (and for some reason also executes much faster):

BEGIN

  LOOP ON (select patientid from prod_P_GeneralData where status = 1) as cur

  BEGIN

  insert into wodan_sofas(admissionid,periodstart,periodend, cardio, cns, coag, liver, renal, resp)

  select s.admissionid, s.periodstart, s.periodend, s.cardio, s.cns, s.coag, s.liver, s.renal, s.resp

  from pr_sofa s

  where s.admissionid_in = cur.patientid

  and s.calculatehour = 5;

  END

END

I assume that teiid starts a transaction in the original version to select each patientid from prod_P_GeneralData (on Sybase). The procedure pr_sofa also works on Sybase. I assume that somehow the resultset that selects patientid from prod_P_GeneralData stays open during the whole execution of the query.

In this new version I assume that the transaction only spans one call to pr_sofa.

If I'm correct with this assumption, would it be possible to provide some sort of hint to teiid for this kind of long running queries?

[shawkins]

> I assume that teiid starts a transaction in the original version to select each patientid from prod_P_GeneralData (on Sybase)

Yes, based upon your autoCommitTxn setting, Teiid is assuming a wrapping transaction should be started for the whole user query as the insert may be performed in multiple batches. 

You can tell Teiid not to start a wrapping transaction by setting autoCommitTxn to OFF.

On the workaround are you submitting that as an anonymous procedure block or calling a virtual procedure?

[gadeyne.bram]

Hi Steven,

It works when I do the following

execute "SET AutoCommitTxn OFF"

Then in a second call execute the anonymous procedure block.

Is there a way to send the SET and the anonymous block in the same call?

I've tried

SET AutoCommitTxn OFF
BEGIN
    ....
END

and

BEGIN
    SET AutoCommitTxn OFF
    ...
END

And both versions with a semicolon after OFF. But in all these cases Teiid gives me a parsing error.

If it is not possible to send this as one call, is it maybe possible to send this as a property in the connection string?

[shawkins]

Unfortunately due to legacy choices the set statement is handled in the client and not a server statement, so it can't be included in the block.

Yes, you can include the setting in the connection properties, or issue it as a single statement.

There is probably a case to be made that we should not be using the detect logic in the same way over an anonymous block as you have the option of explicitly controlling the transaction with "begin atomic".  But we'd still have to detect over each of the block statements.