Uploaded image for project: 'Apache Trafodion'
  1. Apache Trafodion
  2. TRAFODION-916

LP Bug: 1412955 - Master Executor reporting error 8605

    XMLWordPrintableJSON

    Details

      Description

      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.

        Attachments

          Activity

            People

            • Assignee:
              arvind.narain Arvind Narain
              Reporter:
              bwilbanks Buddy Wilbanks
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: