[ https://issues.apache.org/jira/browse/TRAFODION-916?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Suresh Subbiah updated TRAFODION-916: ------------------------------------- Fix Version/s: (was: 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 > > 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)