You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafodion.apache.org by "Alice Chen (JIRA)" <ji...@apache.org> on 2015/07/22 20:18:02 UTC

[jira] [Created] (TRAFODION-748) LP Bug: 1390644 - Spontaneous TransactionManager java IO exceptions

Alice Chen created TRAFODION-748:
------------------------------------

             Summary: LP Bug: 1390644 - Spontaneous TransactionManager java IO exceptions
                 Key: TRAFODION-748
                 URL: https://issues.apache.org/jira/browse/TRAFODION-748
             Project: Apache Trafodion
          Issue Type: Bug
          Components: dtm
            Reporter: Weishiun Tsai
            Assignee: Sean Broeder
            Priority: Blocker
             Fix For: 1.0 (pre-incubation)


When running SQL regression tests on the v1105_0830 and the v1106_0830 daily builds on a HortonWorks cluster, TransactionManager would encounter java IOException, which then causes SQL to fail spontaneously.   The initial development analysis has shown that there is a possibility of out-of-bound array access happening in TrxRegionEndpoint.java

-----------------------------------------------------------------

Here is the initial development analysis:

There is this array of size 100 --
private long[] writeToLogTimes    = new long[100];

And then an index calculated here, as you can see it is modulo 500.  So the change should either be changing it to modulo 100, or changing the above array size to 500. 
3318     synchronized (totalCommits){
3319        lv_totalCommits = totalCommits.incrementAndGet();
3320        lv_timeIndex = (timeIndex.getAndIncrement() % 500);
3321     }

It then fails here where we use the index, that is out of bounds:
3392              writeToLogTimes[lv_timeIndex] = writeToLogEndTime - commitCheckEndTime;

-----------------------------------------------------------------

Here are snippets of the errors from trafodion.dtm.log:

grep ERROR /opt/home/trafodion/v1106_0830/sql/scripts/trafodion.dtm.log

2014-11-07 06:44:35,691 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:44:36,514 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:44:37,335 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:44:37,337 ERROR transactional.TransactionManager: Exception: java.
io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 06:44:37,337 ERROR transactional.TransactionManager: exception in pre
pareCommit (during completion processing): java.util.concurrent.ExecutionExcepti
on: java.io.IOException: java.io.IOException: ERROR Received incorrect number of
results from coprocessor call
2014-11-07 06:44:37,337 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:pr
epareCommit, txid: 3991 retval: 7 CommitUnsuccessfulException
2014-11-07 06:46:41,182 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:46:42,004 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:46:42,829 ERROR transactional.TransactionManager: doPrepareX, resu
lt size: 0
2014-11-07 06:46:42,831 ERROR transactional.TransactionManager: Exception: java.
io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 06:46:42,831 ERROR transactional.TransactionManager: exception in pre
…….

lt size: 0
2014-11-07 10:43:37,704 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:43:38,528 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:43:38,530 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:43:38,530 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:43:38,530 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5581 retval: 7 CommitUnsuccessfulException
2014-11-07 10:45:49,422 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:45:50,243 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:45:51,063 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:45:51,065 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:45:51,065 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:45:51,065 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5585 retval: 7 CommitUnsuccessfulException
2014-11-07 10:48:02,282 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:48:03,104 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:48:03,972 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:48:03,974 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:48:03,974 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:48:03,974 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5589 retval: 7 CommitUnsuccessfulException
2014-11-07 10:50:14,867 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:50:15,690 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:50:16,514 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:50:16,516 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:50:16,516 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:50:16,516 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5593 retval: 7 CommitUnsuccessfulException
2014-11-07 10:52:26,844 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:52:27,709 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:52:28,529 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:52:28,531 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:52:28,531 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:52:28,531 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5597 retval: 7 CommitUnsuccessfulException
2014-11-07 10:54:38,374 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:54:39,198 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:54:40,018 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:54:40,020 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:54:40,021 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:54:40,021 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5601 retval: 7 CommitUnsuccessfulException
2014-11-07 10:56:49,271 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:56:50,096 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:56:50,918 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:56:50,920 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:56:50,921 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:56:50,921 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5605 retval: 7 CommitUnsuccessfulException
2014-11-07 10:59:00,269 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:59:01,094 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:59:01,918 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 10:59:01,920 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:59:01,920 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 10:59:01,920 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5609 retval: 7 CommitUnsuccessfulException
2014-11-07 11:01:11,683 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:01:12,505 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:01:13,326 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:01:13,328 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:01:13,328 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:01:13,328 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5613 retval: 7 CommitUnsuccessfulException
2014-11-07 11:03:22,634 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:03:23,459 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:03:24,293 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:03:24,295 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:03:24,295 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:03:24,295 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5617 retval: 7 CommitUnsuccessfulException
2014-11-07 11:05:33,460 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:05:34,282 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:05:35,102 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:05:35,104 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:05:35,104 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:05:35,104 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5621 retval: 7 CommitUnsuccessfulException
2014-11-07 11:07:44,858 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:07:45,684 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:07:46,548 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:07:46,550 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:07:46,550 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:07:46,550 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5625 retval: 7 CommitUnsuccessfulException
2014-11-07 11:09:58,476 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:09:59,299 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:00,121 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:00,123 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:00,124 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:00,124 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5629 retval: 7 CommitUnsuccessfulException
2014-11-07 11:10:03,269 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:04,089 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:04,911 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:04,913 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:04,914 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:04,914 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5630 retval: 7 CommitUnsuccessfulException
2014-11-07 11:10:08,293 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:09,106 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:09,923 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 11:10:09,925 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:09,925 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 11:10:09,925 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5631 retval: 7 CommitUnsuccessfulException
2014-11-07 17:50:34,932 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 17:50:35,753 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 17:50:36,627 ERROR transactional.TransactionManager: doPrepareX, result size: 0
2014-11-07 17:50:36,629 ERROR transactional.TransactionManager: Exception: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 17:50:36,629 ERROR transactional.TransactionManager: exception in prepareCommit (during completion processing): java.util.concurrent.ExecutionException: java.io.IOException: java.io.IOException: ERROR Received incorrect number of results from coprocessor call
2014-11-07 17:50:36,629 ERROR dtm.HBaseTxClient: Returning from HBaseTxClient:prepareCommit, txid: 5638 retval: 7 CommitUnsuccessfulException



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)