You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tajo.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/09/11 02:59:54 UTC

Build failed in Jenkins: Tajo-master-jdk8-nightly #143

See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/143/changes>

Changes:

[blrunner] TAJO-1727: Avoid to create external table using TableSpace.

------------------------------------------
[...truncated 723548 lines...]
JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase2:379->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t1]

JOIN(9)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t4]

JOIN(9)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase3:393->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t1]

JOIN(8)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t2]

JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2:249->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t2]
 2: type=Broadcast,...> but was:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testOuterJoinAndCaseWhen1:132->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]

SORT(15)
  => Sort...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]

SORT(15)
  => Sort...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2_1:267->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...> but was:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t4]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin2:424->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]
 2: type=Broadcast,...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin3:432->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[e
 1: type=Broadcast, tables=default.b
 2: type=Broadcast, tables=default.c
 3: type=Broadcast, tables=default.d]
 4: type=Broadcast,...> but was:<...ast, tables=default.[d
 1: type=Broadcast, tables=default.c
 2: type=Broadcast, tables=default.b
 3: type=Broadcast, tables=default.e]
 4: type=Broadcast,...>
  TestCrossJoin.testCrossJoinOfOneSmallTableAndJoin:152->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.region]
 2: type=Broadcast,...> but was:<...ast, tables=default.[region
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...>
  TestCrossJoin.testCrossJoinWithThetaJoinConditionInWhere:117->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

PROJECTION(3)
  =>...> but was:<...ast, tables=default.[b]

PROJECTION(3)
  =>...>
  TestCrossJoin.testCrossJoinOfOneSmallTableAndJoin:152->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.region]
 2: type=Broadcast,...> but was:<...ast, tables=default.[region
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...>
  TestCrossJoin.testCrossJoinWithThetaJoinConditionInWhere:117->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

PROJECTION(3)
  =>...> but was:<...ast, tables=default.[b]

PROJECTION(3)
  =>...>
  TestUnionQuery.testUnionAndFilter:698->QueryTestCaseBase.runSimpleTests:604 Result Verification for: 1 th test expected:<...-------------------
[4,2866.83
1,711.56
5,794.47
3,7498.12
2,121.65]
> but was:<...-------------------
[1,711.56
4,2866.83
5,794.47
2,121.65
3,7498.12]
>
  TestOuterJoinWithSubQuery.testLeftOuterJoinWithEmptySubquery1:87->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[jointable12
 1: type=Broadcast, tables=default.lineitem]

SORT(17)
  => Sort...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.jointable12]

SORT(17)
  => Sort...>
  TestOuterJoinWithSubQuery.testLeftOuterJoinWithEmptySubquery1:87->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[jointable12
 1: type=Broadcast, tables=default.lineitem]

SORT(17)
  => Sort...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.jointable12]

SORT(17)
  => Sort...>
  TestInnerJoinQuery.testWhereClauseJoin6:98->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestInnerJoinQuery.testJoinWithMultipleJoinQual1:112->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[ps
 1: type=Broadcast, tables=default.p
 2: type=Broadcast, tables=default.s]
 3: type=Broadcast,...> but was:<...ast, tables=default.[s
 1: type=Broadcast, tables=default.ps
 2: type=Broadcast, tables=default.p]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testBroadcastTwoPartJoin:266->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[orders
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.lineitem]
 3: type=Broadcast,...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.orders]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testInnerJoinWithThetaJoinConditionInWhere:56->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

SELECTION(6)
  => ...> but was:<...ast, tables=default.[b]

SELECTION(6)
  => ...>
  TestInnerJoinQuery.testDifferentTypesJoinCondition:209->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4]

JOIN(5)(INNER)
  =...> but was:<...st, tables=default.t[3]

JOIN(5)(INNER)
  =...>
  TestInnerJoinQuery.testTPCHQ2Join:105->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestInnerJoinQuery.testWhereClauseJoin6:98->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestInnerJoinQuery.testJoinWithMultipleJoinQual1:112->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[ps
 1: type=Broadcast, tables=default.p
 2: type=Broadcast, tables=default.s]
 3: type=Broadcast,...> but was:<...ast, tables=default.[s
 1: type=Broadcast, tables=default.ps
 2: type=Broadcast, tables=default.p]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testBroadcastTwoPartJoin:266->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[orders
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.lineitem]
 3: type=Broadcast,...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.orders]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testInnerJoinWithThetaJoinConditionInWhere:56->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

SELECTION(6)
  => ...> but was:<...ast, tables=default.[b]

SELECTION(6)
  => ...>
  TestInnerJoinQuery.testDifferentTypesJoinCondition:209->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4]

JOIN(5)(INNER)
  =...> but was:<...st, tables=default.t[3]

JOIN(5)(INNER)
  =...>
  TestInnerJoinQuery.testTPCHQ2Join:105->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestDDLBuilder.testBuildDDLForExternalTable:64 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...>
  TestDDLBuilder.testBuildDDLForBaseTable:103 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]');> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]');>
  TestDDLBuilder.testBuildDDLQuotedTableName:90 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...>

Tests run: 1636, Failures: 46, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  1.716 s]
[INFO] Tajo Project POM .................................. SUCCESS [  1.664 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  3.329 s]
[INFO] Tajo Common ....................................... SUCCESS [ 28.747 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  2.282 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  4.533 s]
[INFO] Tajo Plan ......................................... SUCCESS [  6.585 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  1.294 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 45.519 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.488 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 10.074 s]
[INFO] Tajo Storage Common ............................... SUCCESS [  2.550 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 46.063 s]
[INFO] Tajo PullServer ................................... SUCCESS [  0.936 s]
[INFO] Tajo Client ....................................... SUCCESS [  2.603 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  1.904 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [  3.613 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  2.147 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  3.960 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  1.391 s]
[INFO] Tajo Core ......................................... SUCCESS [  6.640 s]
[INFO] Tajo RPC .......................................... SUCCESS [  0.932 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 10.392 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [  0.074 s]
[INFO] Tajo Catalog ...................................... SUCCESS [  1.106 s]
[INFO] Tajo Client Example ............................... SUCCESS [  1.037 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  3.642 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [  2.295 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 31.917 s]
[INFO] Tajo Storage ...................................... SUCCESS [  0.948 s]
[INFO] Tajo Distribution ................................. SUCCESS [  5.643 s]
[INFO] Tajo Core Tests ................................... FAILURE [21:04 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 25:01 min
[INFO] Finished at: 2015-09-11T00:59:35+00:00
[INFO] Final Memory: 141M/1757M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR] 
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR] 
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR]   mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Archiving artifacts
Sending artifact delta relative to Tajo-master-jdk8-nightly #82
Archived 1 artifacts
Archive block size is 32768
Received 0 blocks and 59101930 bytes
Compression is 0.0%
Took 16 sec
Recording test results

Build failed in Jenkins: Tajo-master-jdk8-nightly #145

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/145/changes>

Changes:

[jhkim] TAJO-1830: Fix race condition in HdfsServiceTracker.

[jhkim] TAJO-1831: Add a shutdown hook manager in order to set priorities.

------------------------------------------
[...truncated 232321 lines...]
2015-09-11 06:47:27,709 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441953550479_0629 of type STAGE_COMPLETED
2015-09-11 06:47:27,709 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1441953550479_0629_000004
2015-09-11 06:47:27,709 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(757)) - Scheduling Stage:eb_1441953550479_0629_000004
2015-09-11 06:47:27,709 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1441953550479_0629_000004
2015-09-11 06:47:27,709 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1091)) - eb_1441953550479_0629_000004, Table's volume is approximately 1 MB
2015-09-11 06:47:27,709 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1096)) - eb_1441953550479_0629_000004, The determined number of non-leaf tasks is 1
2015-09-11 06:47:27,709 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1441953550479_0629_000003
2015-09-11 06:47:27,710 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleRangeShuffledFetches(670)) - eb_1441953550479_0629_000004, Try to divide [(2), (1000001)) into 1 sub ranges (total units: 1)
2015-09-11 06:47:27,711 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1 objects are scheduled
2015-09-11 06:47:27,711 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(131)) - Start TaskScheduler
2015-09-11 06:47:27,713 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf903.gq1.ygridcore.net:40443
2015-09-11 06:47:27,713 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:54064/tmp/tajo-jenkins/staging/history/20150911/query-detail/q_1441953550479_0614/eb_1441953550479_0614_000007.hist
2015-09-11 06:47:27,714 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:54064/tajo
2015-09-11 06:47:27,714 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir>
2015-09-11 06:47:27,715 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-09-11 06:47:27,715 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/4)>
2015-09-11 06:47:27,715 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441953550479_0629_000004_000000_00 is changed to TA_PENDING
2015-09-11 06:47:27,715 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1441953550479_0629_000004_000000_00
2015-09-11 06:47:27,715 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:54064/tmp/tajo-jenkins/staging/q_1441953550479_0629/RESULT/part-04-000000-000
2015-09-11 06:47:27,715 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:54064/tmp/tajo-jenkins/staging/q_1441953550479_0629/RESULT/part-04-000000-000
2015-09-11 06:47:27,716 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-11 06:47:27,716 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1441953550479_0629_000004_000000_00 is initialized
2015-09-11 06:47:27,716 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2015-09-11 06:47:27,716 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/4/0_0>
2015-09-11 06:47:27,716 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-11 06:47:27,717 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744398_3574{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-19a4c16e-f15f-4024-bba7-ffb4fcedede4:NORMAL:127.0.0.1:48030|FINALIZED]]} size 0
2015-09-11 06:47:27,717 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created  <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/in/eb_1441953550479_0629_000004/0/0/eb_1441953550479_0629_000003>
2015-09-11 06:47:27,718 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-11 06:47:27,718 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-11 06:47:27,718 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=r, sid=3, partId=0, taskIds=[0_0]
2015-09-11 06:47:27,718 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:54064/tmp/tajo-jenkins/staging/history/20150911/query-detail/q_1441953550479_0614/eb_1441953550479_0614_000002.hist
2015-09-11 06:47:27,721 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744399_3575{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-290c0be2-4730-4565-abad-54ec67b3a160:NORMAL:127.0.0.1:48030|RBW]]} size 0
2015-09-11 06:47:27,722 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:54064/tmp/tajo-jenkins/staging/history/20150911/query-detail/q_1441953550479_0614/eb_1441953550479_0614_000001.hist
2015-09-11 06:47:27,725 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744400_3576{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-19a4c16e-f15f-4024-bba7-ffb4fcedede4:NORMAL:127.0.0.1:48030|RBW]]} size 0
2015-09-11 06:47:27,727 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:54064/tmp/tajo-jenkins/staging/history/20150911/query-detail/q_1441953550479_0614/eb_1441953550479_0614_000004.hist
2015-09-11 06:47:27,729 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744401_3577{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-290c0be2-4730-4565-abad-54ec67b3a160:NORMAL:127.0.0.1:48030|RBW]]} size 0
2015-09-11 06:47:27,730 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:54064/tmp/tajo-jenkins/staging/history/20150911/query-detail/q_1441953550479_0614/eb_1441953550479_0614_000003.hist
2015-09-11 06:47:27,732 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744402_3578{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-19a4c16e-f15f-4024-bba7-ffb4fcedede4:NORMAL:127.0.0.1:48030|RBW]]} size 0
2015-09-11 06:47:27,742 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((2), (1000001)
2015-09-11 06:47:27,742 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/3/0_0/output/output> (start=(2), end=(1000001), last=true)
2015-09-11 06:47:27,743 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=0, length=284, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/3/0_0/output/output>
2015-09-11 06:47:27,743 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=284, fromRemote=false, ebId=eb_1441953550479_0629_000003) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/3/0_0/output/output>
2015-09-11 06:47:27,743 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441953550479_0629_000004_000000_00 is changed to TA_RUNNING
2015-09-11 06:47:27,743 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-09-11 06:47:27,743 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list
2015-09-11 06:47:27,743 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(362)) - ta_1441953550479_0629_000004_000000_00 All fetches are done!
2015-09-11 06:47:27,744 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-11 06:47:27,746 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1441953550479_0629_000004_000000_00] Total merge time: 0 msec
2015-09-11 06:47:27,746 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (close(791)) - Delete file: "fragment": {"id": "eb_1441953550479_0629_000003", "path": <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/6affd2e8-be89-46fd-8447-9e912ebd988a/tajo-localdir/q_1441953550479_0629/output/3/0_0/output/output",> "start": 0,"length": 284}
2015-09-11 06:47:27,749 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48030 is added to blk_1073744403_3579{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-290c0be2-4730-4565-abad-54ec67b3a160:NORMAL:127.0.0.1:48030|FINALIZED]]} size 0
2015-09-11 06:47:27,750 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441953550479_0629_000004_000000_00 is changed to TA_SUCCEEDED
2015-09-11 06:47:27,750 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1441953550479_0629_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-11 06:47:27,750 INFO: org.apache.tajo.querymaster.Stage (transition(1345)) - Stage - eb_1441953550479_0629_000004 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-09-11 06:47:27,750 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-11 06:47:27,751 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-11 06:47:27,751 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1441953550479_0629_000004 (total=1, success=1, killed=0)
2015-09-11 06:47:27,751 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441953550479_0629 of type STAGE_COMPLETED
2015-09-11 06:47:27,751 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1441953550479_0629_000005
2015-09-11 06:47:27,751 INFO: org.apache.tajo.querymaster.Query (transition(802)) - Complete Stage[eb_1441953550479_0629_000004], State: SUCCEEDED, 4/4. 
2015-09-11 06:47:27,751 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441953550479_0629 of type QUERY_COMPLETED
2015-09-11 06:47:27,751 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1441953550479_0629_000004
2015-09-11 06:47:27,752 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1441953550479_0629 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-09-11 06:47:27,752 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(292)) - Query completion notified from q_1441953550479_0629 final state: QUERY_SUCCEEDED
2015-09-11 06:47:27,752 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(169)) - Stopping QueryMasterTask:q_1441953550479_0629
2015-09-11 06:47:27,753 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(469)) - Cleanup resources of all workers. Query: q_1441953550479_0629, workers: 1
2015-09-11 06:47:27,752 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(253)) - Received QueryMaster heartbeat:q_1441953550479_0629,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf903.gq1.ygridcore.net
2015-09-11 06:47:27,753 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1441953550479_0629
2015-09-11 06:47:27,753 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-11 06:47:27,753 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1441953550479_0629
2015-09-11 06:47:27,753 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(185)) - Stopped QueryMasterTask:q_1441953550479_0629
2015-09-11 06:47:27,846 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1
2015-09-11 06:47:27,847 INFO: org.apache.tajo.storage.FileTablespace (getSplits(569)) - Total # of splits: 1
2015-09-11 06:47:27,850 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 09234876-4f83-4299-b446-d2d75d6f705c,q_1441953550479_0629, 5 rows
2015-09-11 06:47:27,850 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 09234876-4f83-4299-b446-d2d75d6f705c,q_1441953550479_0629, 0 rows
2015-09-11 06:47:27,852 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073744403_3579 127.0.0.1:48030 
Run: testLeftOuterJoinWithNull1[0] Used memory: 498 MBytes, Active Threads:261
2015-09-11 06:47:27,855 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: explain select   c_custkey,   orders.o_orderkey,   coalesce(orders.o_orderstatus, 'N/A'),   orders.o_orderdate from   customer left outer join orders on c_custkey = o_orderkey where o_orderkey is null order by   c_custkey, o_orderkey
2015-09-11 06:47:27,893 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------

PROJECTION(5)
  => Targets: default.customer.c_custkey (INT4), default.orders.o_orderkey (INT4), ?coalesce (TEXT), default.orders.o_orderdate (TEXT)
  => out schema: {(4) default.customer.c_custkey (INT4), default.orders.o_orderkey (INT4), ?coalesce (TEXT), default.orders.o_orderdate (TEXT)}
  => in  schema: {(20) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT), default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT), ?coalesce (TEXT), ?isnullpredicate_1 (BOOLEAN), ?equals_2 (BOOLEAN)}
   SORT(4)
     => Sort Keys: default.customer.c_custkey (INT4) (asc),default.orders.o_orderkey (INT4) (asc)
      SELECTION(3)
        => Search Cond: default.orders.o_orderkey (INT4) IS NULL
         JOIN(2)(LEFT_OUTER)
           => Join Cond: default.customer.c_custkey (INT4) = default.orders.o_orderkey (INT4)
           => target list: default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT), default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT), coalesce(default.orders.o_orderstatus (TEXT),N/A) as ?coalesce, default.orders.o_orderkey (INT4) IS NULL as ?isnullpredicate_1, default.customer.c_custkey (INT4) = default.orders.o_orderkey (INT4) as ?equals_2
           => out schema: {(20) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT), default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT), ?coalesce (TEXT), ?isnullpredicate_1 (BOOLEAN), ?equals_2 (BOOLEAN)}
           => in schema: {(17) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT), default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT)}
            SCAN(1) on default.orders
              => target list: default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT)
              => out schema: {(9) default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT)}
              => in schema: {(9) default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT)}
            SCAN(0) on default.customer
              => target list: default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT)
              => out schema: {(8) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT)}
              => in schema: {(8) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT)}

2015-09-11 06:47:27,894 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-11 06:47:27,895 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
	> ProjectionNode is eliminated.
[#ROOT]
	> Non-optimized join order: (default.customer ⟕ default.orders) (cost: 52779.600000000006)
	> Optimized join order    : (default.customer ⟕ default.orders) (cost: 79169.40000000001)
-----------------------------

SORT(4)
  => Sort Keys: default.customer.c_custkey (INT4) (asc),default.orders.o_orderkey (INT4) (asc)
   SELECTION(3)
     => Search Cond: default.orders.o_orderkey (INT4) IS NULL
      JOIN(7)(LEFT_OUTER)
        => Join Cond: default.customer.c_custkey (INT4) = default.orders.o_orderkey (INT4)
        => target list: default.customer.c_custkey (INT4), default.orders.o_orderkey (INT4), coalesce(default.orders.o_orderstatus (TEXT),N/A) as ?coalesce, default.orders.o_orderdate (TEXT)
        => out schema: {(4) default.customer.c_custkey (INT4), default.orders.o_orderkey (INT4), ?coalesce (TEXT), default.orders.o_orderdate (TEXT)}
        => in schema: {(4) default.customer.c_custkey (INT4), default.orders.o_orderkey (INT4), default.orders.o_orderdate (TEXT), default.orders.o_orderstatus (TEXT)}
         SCAN(1) on default.orders
           => target list: default.orders.o_orderkey (INT4), default.orders.o_orderdate (TEXT), default.orders.o_orderstatus (TEXT)
           => out schema: {(3) default.orders.o_orderkey (INT4), default.orders.o_orderdate (TEXT), default.orders.o_orderstatus (TEXT)}
           => in schema: {(9) default.orders.o_orderkey (INT4), default.orders.o_custkey (INT4), default.orders.o_orderstatus (TEXT), default.orders.o_totalprice (FLOAT8), default.orders.o_orderdate (TEXT), default.orders.o_orderpriority (TEXT), default.orders.o_clerk (TEXT), default.orders.o_shippriority (INT4), default.orders.o_comment (TEXT)}
         SCAN(0) on default.customer
           => target list: default.customer.c_custkey (INT4)
           => out schema: {(1) default.customer.c_custkey (INT4)}
           => in schema: {(8) default.customer.c_custkey (INT4), default.customer.c_name (TEXT), default.customer.c_address (TEXT), default.customer.c_nationkey (INT4), default.customer.c_phone (TEXT), default.customer.c_acctbal (FLOAT8), default.customer.c_mktsegment (TEXT), default.customer.c_comment (TEXT)}

2015-09-11 06:47:27,895 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-11 06:47:27,895 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-11 06:47:27,896 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1441953550479_0630
2015-09-11 06:47:27,896 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: explain global select   c_custkey,   orders.o_orderkey,   coalesce(orders.o_orderstatus, 'N/A'),   orders.o_orderdate from   customer left outer join orders on c_custkey = o_orderkey where o_orderkey is null order by   c_custkey, o_orderkey
Killed

Results :

Failed tests: 
  TestUnionQuery.testUnionAndFilter:698->QueryTestCaseBase.runSimpleTests:604 Result Verification for: 1 th test expected:<...-------------------
[4,2866.83
1,711.56
5,794.47
3,7498.12
2,121.65]
> but was:<...-------------------
[1,711.56
4,2866.83
5,794.47
2,121.65
3,7498.12]
>
  TestOuterJoinWithSubQuery.testLeftOuterJoinWithEmptySubquery1:87->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[jointable12
 1: type=Broadcast, tables=default.lineitem]

SORT(17)
  => Sort...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.jointable12]

SORT(17)
  => Sort...>
  TestOuterJoinWithSubQuery.testLeftOuterJoinWithEmptySubquery1:87->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[jointable12
 1: type=Broadcast, tables=default.lineitem]

SORT(17)
  => Sort...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.jointable12]

SORT(17)
  => Sort...>

Tests run: 565, Failures: 3, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  2.086 s]
[INFO] Tajo Project POM .................................. SUCCESS [  1.867 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  2.844 s]
[INFO] Tajo Common ....................................... SUCCESS [ 29.675 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  2.519 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  4.991 s]
[INFO] Tajo Plan ......................................... SUCCESS [  7.198 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  1.311 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 50.763 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.445 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [  9.533 s]
[INFO] Tajo Storage Common ............................... SUCCESS [  2.951 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 50.783 s]
[INFO] Tajo PullServer ................................... SUCCESS [  1.031 s]
[INFO] Tajo Client ....................................... SUCCESS [  2.668 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  2.309 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [  4.288 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  2.351 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  4.626 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  1.444 s]
[INFO] Tajo Core ......................................... SUCCESS [  7.156 s]
[INFO] Tajo RPC .......................................... SUCCESS [  0.910 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 11.159 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [  0.066 s]
[INFO] Tajo Catalog ...................................... SUCCESS [  1.000 s]
[INFO] Tajo Client Example ............................... SUCCESS [  1.033 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  4.295 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [  2.404 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 36.060 s]
[INFO] Tajo Storage ...................................... SUCCESS [  0.940 s]
[INFO] Tajo Distribution ................................. SUCCESS [  5.305 s]
[INFO] Tajo Core Tests ................................... FAILURE [08:28 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 12:46 min
[INFO] Finished at: 2015-09-11T06:47:28+00:00
[INFO] Final Memory: 156M/2111M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests> && /home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.8/jre/bin/java -Xms512m -Xmx1024m -XX:MaxPermSize=152m -Dfile.encoding=UTF-8 -Dderby.storage.pageSize=1024 -Dderby.stream.error.file=/dev/null -jar <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire/surefirebooter6083355968695518263.jar> <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire/surefire6737121296063907616tmp> <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire/surefire_143892282505817273060tmp>
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/PluginExecutionException
[ERROR] 
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR]   mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Archiving artifacts
Sending artifact delta relative to Tajo-master-jdk8-nightly #82
Archived 1 artifacts
Archive block size is 32768
Received 0 blocks and 59137848 bytes
Compression is 0.0%
Took 16 sec
Recording test results

Build failed in Jenkins: Tajo-master-jdk8-nightly #144

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/144/changes>

Changes:

[blrunner] TAJO-1739: Add a statement for adding partition to TajoDump.

[hyunsik] TAJO-1817: Improve SQL parser error message.

------------------------------------------
[...truncated 723784 lines...]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testInnerJoinWithThetaJoinConditionInWhere:56->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

SELECTION(6)
  => ...> but was:<...ast, tables=default.[b]

SELECTION(6)
  => ...>
  TestInnerJoinQuery.testDifferentTypesJoinCondition:209->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4]

JOIN(5)(INNER)
  =...> but was:<...st, tables=default.t[3]

JOIN(5)(INNER)
  =...>
  TestInnerJoinQuery.testTPCHQ2Join:105->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestInnerJoinQuery.testWhereClauseJoin6:98->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestInnerJoinQuery.testJoinWithMultipleJoinQual1:112->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[ps
 1: type=Broadcast, tables=default.p
 2: type=Broadcast, tables=default.s]
 3: type=Broadcast,...> but was:<...ast, tables=default.[s
 1: type=Broadcast, tables=default.ps
 2: type=Broadcast, tables=default.p]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testBroadcastTwoPartJoin:266->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[orders
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.lineitem]
 3: type=Broadcast,...> but was:<...ast, tables=default.[lineitem
 1: type=Broadcast, tables=default.part
 2: type=Broadcast, tables=default.orders]
 3: type=Broadcast,...>
  TestInnerJoinQuery.testInnerJoinWithThetaJoinConditionInWhere:56->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[a]

SELECTION(6)
  => ...> but was:<...ast, tables=default.[b]

SELECTION(6)
  => ...>
  TestInnerJoinQuery.testDifferentTypesJoinCondition:209->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4]

JOIN(5)(INNER)
  =...> but was:<...st, tables=default.t[3]

JOIN(5)(INNER)
  =...>
  TestInnerJoinQuery.testTPCHQ2Join:105->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[part
 1: type=Broadcast, tables=default.supplier]
 2: type=Broadcast,...> but was:<...ast, tables=default.[supplier
 1: type=Broadcast, tables=default.part]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase1:361->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t1]

JOIN(8)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t2]

JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase2:379->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t1]

JOIN(9)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t4]

JOIN(9)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase3:393->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t1]

JOIN(8)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t2]

JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2:249->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t2]
 2: type=Broadcast,...> but was:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testOuterJoinAndCaseWhen1:132->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]

SORT(15)
  => Sort...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]

SORT(15)
  => Sort...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2_1:267->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...> but was:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t4]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin2:424->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]
 2: type=Broadcast,...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin3:432->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[e
 1: type=Broadcast, tables=default.b
 2: type=Broadcast, tables=default.c
 3: type=Broadcast, tables=default.d]
 4: type=Broadcast,...> but was:<...ast, tables=default.[d
 1: type=Broadcast, tables=default.c
 2: type=Broadcast, tables=default.b
 3: type=Broadcast, tables=default.e]
 4: type=Broadcast,...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase1:361->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t1]

JOIN(8)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t2]

JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase2:379->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t1]

JOIN(9)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t4]

JOIN(9)(RIGHT_OUTE...>
  TestOuterJoinQuery.testRightOuterJoinPredicationCaseByCase3:393->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t1]

JOIN(8)(RIGHT_OUTE...> but was:<...st, tables=default.t[1
 1: type=Broadcast, tables=default.t2]

JOIN(8)(RIGHT_OUTE...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2:249->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t2]
 2: type=Broadcast,...> but was:<...st, tables=default.t[2
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testOuterJoinAndCaseWhen1:132->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]

SORT(15)
  => Sort...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]

SORT(15)
  => Sort...>
  TestOuterJoinQuery.testLeftOuterJoinPredicationCaseByCase2_1:267->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...st, tables=default.t[4
 1: type=Broadcast, tables=default.t3]
 2: type=Broadcast,...> but was:<...st, tables=default.t[3
 1: type=Broadcast, tables=default.t4]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin2:424->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[b
 1: type=Broadcast, tables=default.c]
 2: type=Broadcast,...> but was:<...ast, tables=default.[c
 1: type=Broadcast, tables=default.b]
 2: type=Broadcast,...>
  TestOuterJoinQuery.testLeftOuterJoin3:432->QueryTestCaseBase.runSimpleTests:587 Plan Verification for: 1 th test expected:<...ast, tables=default.[e
 1: type=Broadcast, tables=default.b
 2: type=Broadcast, tables=default.c
 3: type=Broadcast, tables=default.d]
 4: type=Broadcast,...> but was:<...ast, tables=default.[d
 1: type=Broadcast, tables=default.c
 2: type=Broadcast, tables=default.b
 3: type=Broadcast, tables=default.e]
 4: type=Broadcast,...>
  TestUnionQuery.testUnionAndFilter:698->QueryTestCaseBase.runSimpleTests:604 Result Verification for: 1 th test expected:<...-------------------
[4,2866.83
1,711.56
5,794.47
3,7498.12
2,121.65]
> but was:<...-------------------
[1,711.56
4,2866.83
5,794.47
2,121.65
3,7498.12]
>
  TestDDLBuilder.testBuildDDLForExternalTable:64 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...>
  TestDDLBuilder.testBuildDDLForBaseTable:103 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]');> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]');>
  TestDDLBuilder.testBuildDDLQuotedTableName:90 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...>

Tests run: 1638, Failures: 46, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  1.652 s]
[INFO] Tajo Project POM .................................. SUCCESS [  1.543 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  2.856 s]
[INFO] Tajo Common ....................................... SUCCESS [ 28.321 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  2.267 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  4.711 s]
[INFO] Tajo Plan ......................................... SUCCESS [  6.436 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  1.238 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 46.326 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.440 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [  9.524 s]
[INFO] Tajo Storage Common ............................... SUCCESS [  2.580 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 45.331 s]
[INFO] Tajo PullServer ................................... SUCCESS [  0.905 s]
[INFO] Tajo Client ....................................... SUCCESS [  2.812 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  1.848 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [  3.512 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  2.166 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  3.789 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  1.385 s]
[INFO] Tajo Core ......................................... SUCCESS [  6.181 s]
[INFO] Tajo RPC .......................................... SUCCESS [  0.963 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [  9.666 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [  0.166 s]
[INFO] Tajo Catalog ...................................... SUCCESS [  0.972 s]
[INFO] Tajo Client Example ............................... SUCCESS [  1.027 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  3.276 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [  2.387 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 30.383 s]
[INFO] Tajo Storage ...................................... SUCCESS [  0.980 s]
[INFO] Tajo Distribution ................................. SUCCESS [  5.448 s]
[INFO] Tajo Core Tests ................................... FAILURE [21:06 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 24:59 min
[INFO] Finished at: 2015-09-11T05:27:31+00:00
[INFO] Final Memory: 147M/1749M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR] 
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR] 
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR]   mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Archiving artifacts
Sending artifact delta relative to Tajo-master-jdk8-nightly #82
Archived 1 artifacts
Archive block size is 32768
Received 0 blocks and 59111369 bytes
Compression is 0.0%
Took 15 sec
Recording test results