[
https://issues.apache.org/jira/browse/TRAFODION-916?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Pierre Smits updated TRAFODION-916:
-----------------------------------
Fix Version/s: (was: 2.1-incubating)
2.2.0
> LP Bug: 1412955 - Master Executor reporting error 8605
> ------------------------------------------------------
>
> Key: TRAFODION-916
> URL: https://issues.apache.org/jira/browse/TRAFODION-916
> Project: Apache Trafodion
> Issue Type: Bug
> Components: connectivity-mxosrvr
> Reporter: Buddy Wilbanks
> Assignee: Arvind Narain
> Priority: Critical
> Labels: 8605, commit, transaction
> Fix For: 2.2.0
>
>
> We are seeing this error message streaming during the order entry benchmark.
> 2015-01-17 11:25:49,116, ERROR, SQL, Node Number: 0, CPU: 0, PIN: 63243,
> Process Name: $Z001GLY, SQLCODE: 8605, QID: MXID110000632432122882535634324540
> 00000000206U3333300_24_STMT_COMMIT_1, *** ERROR[8605] Committing a
> transaction which has not started.
> 2015-01-17 11:25:50,667, ERROR, SQL, Node Number: 0, CPU: 0, PIN: 63243,
> Process Name: $Z001GLY, SQLCODE: 8605, QID: MXID110000632432122882535634324540
> 00000000206U3333300_24_STMT_COMMIT_1, *** ERROR[8605] Committing a
> transaction which has not started.
> 2015-01-17 11:26:17,823, ERROR, SQL, Node Number: 0, CPU: 0, PIN: 63243,
> Process Name: $Z001GLY, SQLCODE: 8605, QID: MXID110000632432122882535634324540
> 00000000206U3333300_24_STMT_COMMIT_1, *** ERROR[8605] Committing a
> transaction which has not started.
> The counts are prolific. The master above shows every couple of seconds.
> master_exec_0_13398.log:10241
> master_exec_0_13942.log:12065
> master_exec_0_17055.log:10110
> master_exec_0_19990.log:11068
> master_exec_0_20733.log:11818
> master_exec_0_21408.log:10560
> master_exec_0_22203.log:10633
> master_exec_0_22274.log:1223
> master_exec_0_24271.log:10096
> master_exec_0_24852.log:1477
> master_exec_0_24895.log:10791
> master_exec_0_24990.log:12213
> master_exec_0_26398.log:11618
> master_exec_0_26536.log:1298
> The only place where the error occurs is when commitTransaction is called and
> there isn’t an xnInProgress.
> executor/ex_transaction.cpp:
> EXE_COMMIT_TRANSACTION_ERROR, &errorCond_);
> exp/ExpErrorEnums.h: EXE_COMMIT_TRANSACTION_ERROR = 8605,
> short ExTransaction::commitTransaction(NABoolean waited)
> {
> dp2Xns_ = FALSE;
> if (! xnInProgress())
> {
> // Set the transaDiagsArea.
> // This is the first error. So reset the diags area.
> if (transDiagsArea_)
> {
> transDiagsArea_->decrRefCount();
> transDiagsArea_ = NULL;
> }
> ExRaiseSqlError(heap_, &transDiagsArea_,
> EXE_COMMIT_TRANSACTION_ERROR, &errorCond_);
> return -1;
> }
> It must have something to do with inherited transactions. inheritTransaction
> is the only place where we set XnInProgress_ to false. The order entry does
> not use ESPs so there is no reason to have an inherited transaction.
> Guy has shown the problem with a simple test case.
> First scenario:
> - I’m going to do a prepare/exec without using transactions.
> /home/squser2> trafci.sh
> Welcome to Trafodion Command Interface
> Copyright(C) 2013-2014 Hewlett-Packard Development Company, L.P.
> User Name: squser2
> Host Name/IP Address: n001:21000
> Password:
> Connected to Trafodion
> SQL>set schema mxoltp;
> --- SQL operation complete.
> SQL>prepare cmd from select [first 10]* from tbl500;
> *** WARNING[6008] Statistics for column (CNT) from table
> TRAFODION.MXOLTP.TBL500 were not available. As a result, the access path
> chosen might not be the best possible. [2015-01-20 19:26:52]
> --- SQL command prepared.
> SQL>execute cmd;
> CNT COL1 COL2 COL3 COL4 COL5 COL6
> COL7 COL10
>
> ---------- ---------- ---------- ---------- ---------- ---------- ----------
> ----------
> --------------------------------------------------------------------------------------------------------------------------------
> 3 1 2 0 4 5 6
> 7
> AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAL
> …
> 176 1 2 1 4 5 6
> 7
> AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAL
> --- 10 row(s) selected.
> SQL>exit
> /home/squser2>
> Here’s the master_exec_ log.
> /opt/hp/squser2/git150118/logs> tail -f master_exec_6_63946.log
> 2015-01-20 19:26:52,591, INFO, SQL, Node Number: 0, CPU: 6, PIN: 63946,
> Process Name: $Z061H71, SQLCODE: 6008, QID:
> MXID11006063946212288460034592277000000000406U3333300_1177_CMD, ***
> WARNING[6008] Statistics for column (CNT) from table TRAFODION.MXOLTP.TBL500
> were not available. As a result, the access path chosen might not be the best
> possible.
> ^C
> /opt/hp/squser2/git150118/logs>
> Second Scenario :
> - I’m going to do a prepare and do the exec within a transactions.
> /home/squser2> trafci.sh
> Welcome to Trafodion Command Interface
> Copyright(C) 2013-2014 Hewlett-Packard Development Company, L.P.
> User Name: squser2
> Host Name/IP Address: n001:21000
> Password:
> Connected to Trafodion
> SQL>set schema mxoltp;
> --- SQL operation complete.
> SQL>prepare cmd from select [first 10]* from tbl500;
> *** WARNING[6008] Statistics for column (CNT) from table
> TRAFODION.MXOLTP.TBL500 were not available. As a result, the access path
> chosen might not be the best possible. [2015-01-20 19:35:04]
> --- SQL command prepared.
> SQL>begin work;
> --- SQL operation complete.
> SQL>execute cmd;
> CNT COL1 COL2 COL3 COL4 COL5 COL6
> COL7 COL10
>
> ---------- ---------- ---------- ---------- ---------- ---------- ----------
> ----------
> --------------------------------------------------------------------------------------------------------------------------------
> 3 1 2 0 4 5 6
> 7
> AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAL
> …
> 176 1 2 1 4 5 6
> 7
> AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAL
> --- 10 row(s) selected.
> SQL>commit work;
> --- SQL operation complete.
> SQL>exit
> /home/squser2>
> Here’s the master_exec_ log.
> 2015-01-20 19:35:04,011, INFO, SQL, Node Number: 0, CPU: 4, PIN: 2006,
> Process Name: $Z0401MB, SQLCODE: 6008, QID:
> MXID11004002006212288460034800667000000000406U3333300_1177_CMD, ***
> WARNING[6008] Statistics for column (CNT) from table TRAFODION.MXOLTP.TBL500
> were not available. As a result, the access path chosen might not be the best
> possible.
> 2015-01-20 19:36:25,843, INFO, SQL.ESP, Node Number: 0, CPU: 4, PIN: 21984,
> Process Name: $Z040HY4,,, An ESP process is launched.
> 2015-01-20 19:36:38,979, ERROR, SQL, Node Number: 0, CPU: 4, PIN: 2006,
> Process Name: $Z0401MB, SQLCODE: 8609, QID:
> MXID11004002006212288460034800667000000000406U3333300_1160_STMT_ROLLBACK_1,
> *** ERROR[8609] Waited rollback performed without starting a transaction.
> Notice in my second scenario here, an ESP is started. Why?????
> And the 8609 msg shows up.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
