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/14 10:44:37 UTC
Build failed in Jenkins: Tajo-master-jdk8-nightly #148
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/148/changes>
Changes:
[jhkim] TAJO-1340: Change the default output file format.
------------------------------------------
[...truncated 743587 lines...]
2015-09-14 08:43:44,205 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-14 08:43:44,205 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442218931268_2118_000001_000000_01 is initialized
2015-09-14 08:43:44,205 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:0) :
2015-09-14 08:43:44,205 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/5d5ad49d-1c60-4ca7-af90-c0185355bd41/tajo-localdir/q_1442218931268_2118/output/1/0_1>
2015-09-14 08:43:44,205 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-14 08:43:44,205 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442218931268_2118_000001_000000_01 is changed to TA_RUNNING
2015-09-14 08:43:44,208 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073748646_7822 127.0.0.1:34580
2015-09-14 08:43:44,209 ERROR: org.apache.tajo.worker.TaskImpl (run(408)) - internal error: testQueryFailure
org.apache.tajo.exception.TajoInternalError: internal error: testQueryFailure
at org.apache.tajo.engine.function.FailFunction.eval(FailFunction.java:65)
at org.apache.tajo.plan.function.ClassBasedScalarFunctionInvoke.eval(ClassBasedScalarFunctionInvoke.java:55)
at org.apache.tajo.plan.expr.GeneralFunctionEval.eval(GeneralFunctionEval.java:60)
at org.apache.tajo.engine.planner.Projector.eval(Projector.java:74)
at org.apache.tajo.engine.planner.physical.SeqScanExec.next(SeqScanExec.java:292)
at org.apache.tajo.engine.planner.physical.StoreTableExec.next(StoreTableExec.java:128)
at org.apache.tajo.worker.TaskImpl.run(TaskImpl.java:403)
at org.apache.tajo.worker.TaskContainer.run(TaskContainer.java:65)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2015-09-14 08:43:44,212 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:34580 is added to blk_1073748647_7823{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-eeefacfc-074f-45c8-a6a9-16bc12df81af:NORMAL:127.0.0.1:34580|FINALIZED]]} size 0
2015-09-14 08:43:44,213 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442218931268_2118_000001_000000_01 is changed to TA_FAILED
2015-09-14 08:43:44,213 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442218931268_2118_000001_000000_01 completed. Worker's task counter - total:2, succeeded: 0, killed: 0, failed: 2
2015-09-14 08:43:44,213 ERROR: org.apache.tajo.querymaster.TaskAttempt (transition(438)) - ta_1442218931268_2118_000001_000000_01 FROM asf900.gq1.ygridcore.net >> internal error: testQueryFailure
2015-09-14 08:43:44,213 INFO: org.apache.tajo.querymaster.Task (transition(663)) - ====================================================================================
2015-09-14 08:43:44,213 INFO: org.apache.tajo.querymaster.Task (transition(664)) - >>> Task Failed: ta_1442218931268_2118_000001_000000_01, retry:true, attempts:2 <<<
2015-09-14 08:43:44,213 INFO: org.apache.tajo.querymaster.Task (transition(666)) - ====================================================================================
2015-09-14 08:43:44,214 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (increaseConcurrency(521)) - Assigned host : 127.0.0.1, Unknown Volume : -1, Concurrency : 1
2015-09-14 08:43:44,215 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/5d5ad49d-1c60-4ca7-af90-c0185355bd41/tajo-localdir/q_1442218931268_2118/output/1)>
2015-09-14 08:43:44,215 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (assignToLeafTasks(915)) - Assigned Local/Rack/Total: (0/3/3), Attempted Cancel/Assign/Total: (0/3/3), Locality: 0.00%, Rack host: asf900.gq1.ygridcore.net
2015-09-14 08:43:44,215 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442218931268_2118_000001_000000_02 is changed to TA_PENDING
2015-09-14 08:43:44,215 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1442218931268_2118_000001_000000_02
2015-09-14 08:43:44,216 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:46969/tmp/tajo-jenkins/staging/q_1442218931268_2118/RESULT/part-01-000000-000
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:46969/tmp/tajo-jenkins/staging/q_1442218931268_2118/RESULT/part-01-000000-000
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442218931268_2118_000001_000000_02 is initialized
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:0) :
2015-09-14 08:43:44,216 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/5d5ad49d-1c60-4ca7-af90-c0185355bd41/tajo-localdir/q_1442218931268_2118/output/1/0_2>
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-14 08:43:44,216 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442218931268_2118_000001_000000_02 is changed to TA_RUNNING
2015-09-14 08:43:44,218 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073748647_7823 127.0.0.1:34580
2015-09-14 08:43:44,219 ERROR: org.apache.tajo.worker.TaskImpl (run(408)) - internal error: testQueryFailure
org.apache.tajo.exception.TajoInternalError: internal error: testQueryFailure
at org.apache.tajo.engine.function.FailFunction.eval(FailFunction.java:65)
at org.apache.tajo.plan.function.ClassBasedScalarFunctionInvoke.eval(ClassBasedScalarFunctionInvoke.java:55)
at org.apache.tajo.plan.expr.GeneralFunctionEval.eval(GeneralFunctionEval.java:60)
at org.apache.tajo.engine.planner.Projector.eval(Projector.java:74)
at org.apache.tajo.engine.planner.physical.SeqScanExec.next(SeqScanExec.java:292)
at org.apache.tajo.engine.planner.physical.StoreTableExec.next(StoreTableExec.java:128)
at org.apache.tajo.worker.TaskImpl.run(TaskImpl.java:403)
at org.apache.tajo.worker.TaskContainer.run(TaskContainer.java:65)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2015-09-14 08:43:44,222 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:34580 is added to blk_1073748648_7824{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-110b18d5-3a8c-4ec1-a5f4-5b1e4f966f77:NORMAL:127.0.0.1:34580|FINALIZED]]} size 0
2015-09-14 08:43:44,223 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442218931268_2118_000001_000000_02 is changed to TA_FAILED
2015-09-14 08:43:44,223 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442218931268_2118_000001_000000_02 completed. Worker's task counter - total:3, succeeded: 0, killed: 0, failed: 3
2015-09-14 08:43:44,223 ERROR: org.apache.tajo.querymaster.TaskAttempt (transition(438)) - ta_1442218931268_2118_000001_000000_02 FROM asf900.gq1.ygridcore.net >> internal error: testQueryFailure
2015-09-14 08:43:44,223 INFO: org.apache.tajo.querymaster.Task (transition(663)) - ====================================================================================
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.Task (transition(664)) - >>> Task Failed: ta_1442218931268_2118_000001_000000_02, retry:false, attempts:3 <<<
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.Task (transition(666)) - ====================================================================================
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1442218931268_2118_000001 (total=1, success=0, killed=0)
2015-09-14 08:43:44,224 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-14 08:43:44,225 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442218931268_2118 of type STAGE_COMPLETED
2015-09-14 08:43:44,225 INFO: org.apache.tajo.querymaster.Query (transition(802)) - Complete Stage[eb_1442218931268_2118_000001], State: FAILED, 1/1.
2015-09-14 08:43:44,225 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442218931268_2118 of type QUERY_COMPLETED
2015-09-14 08:43:44,225 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1442218931268_2118_000001
2015-09-14 08:43:44,225 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1442218931268_2118 Query Transitioned from QUERY_RUNNING to QUERY_FAILED
2015-09-14 08:43:44,225 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(292)) - Query completion notified from q_1442218931268_2118 final state: QUERY_FAILED
2015-09-14 08:43:44,226 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(253)) - Received QueryMaster heartbeat:q_1442218931268_2118,state=QUERY_FAILED,progress=0.0, queryMaster=asf900.gq1.ygridcore.net
2015-09-14 08:43:44,226 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(169)) - Stopping QueryMasterTask:q_1442218931268_2118
2015-09-14 08:43:44,226 WARN: org.apache.tajo.master.QueryInProgress (heartbeat(268)) - q_1442218931268_2118 is stopped because
2015-09-14 08:43:44,226 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(469)) - Cleanup resources of all workers. Query: q_1442218931268_2118, workers: 1
2015-09-14 08:43:44,226 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1442218931268_2118
2015-09-14 08:43:44,227 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-14 08:43:44,227 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(185)) - Stopped QueryMasterTask:q_1442218931268_2118
2015-09-14 08:43:44,227 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1442218931268_2118
2015-09-14 08:43:44,310 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(239)) - SQL: CREATE DATABASE IF NOT EXISTS "TestTajoCliNegatives"
2015-09-14 08:43:44,310 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestTajoCliNegatives
2015-09-14 08:43:44,311 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-14 08:43:44,311 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestTajoCliNegatives
2015-09-14 08:43:44,311 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-14 08:43:44,311 INFO: org.apache.tajo.master.exec.DDLExecutor (createDatabase(247)) - database "TestTajoCliNegatives" is already exists.
Run: testDescTable Used memory: 638 MBytes, Active Threads:388
2015-09-14 08:43:44,314 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session d825be70-852b-491b-85b4-3026a9b62439 is removed.
2015-09-14 08:43:44,318 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session f7c77771-9fe0-4654-90e6-ab393819bc32 is removed.
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.512 sec - in org.apache.tajo.cli.tsql.TestTajoCliNegatives
Running org.apache.tajo.cli.tsql.TestDefaultCliOutputFormatter
2015-09-14 08:43:44,324 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session 49dae939-9fda-4568-89c5-dc7f9b54e484 is created.
2015-09-14 08:43:44,327 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 49dae939-9fda-4568-89c5-dc7f9b54e484 is removed.
2015-09-14 08:43:44,331 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session bcb6f123-d35b-4bee-8543-0ada53094528 is created.
2015-09-14 08:43:44,332 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session bcb6f123-d35b-4bee-8543-0ada53094528 is removed.
2015-09-14 08:43:44,336 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session 3b5a9ffd-507e-4862-9211-47a21fa9af78 is created.
2015-09-14 08:43:44,341 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 3b5a9ffd-507e-4862-9211-47a21fa9af78 is removed.
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.022 sec - in org.apache.tajo.cli.tsql.TestDefaultCliOutputFormatter
Running org.apache.tajo.cli.tsql.TestSimpleParser
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.002 sec - in org.apache.tajo.cli.tsql.TestSimpleParser
Running org.apache.tajo.cli.tsql.commands.TestHdfsCommand
2015-09-14 08:43:44,347 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session f46e8b8d-ab39-4063-8a4d-e5aa1deaf1fa is created.
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.042 sec - in org.apache.tajo.cli.tsql.commands.TestHdfsCommand
Running org.apache.tajo.cli.tsql.commands.TestExecExternalShellCommand
2015-09-14 08:43:44,390 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session 3f68054f-2d31-4f4f-8202-b85dfd188c5a is created.
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec - in org.apache.tajo.cli.tsql.commands.TestExecExternalShellCommand
2015-09-14 08:43:44,412 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
Sep 14, 2015 8:25:14 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:14 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 14, 2015 8:25:36 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
2015-09-14 08:43:44,413 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
2015-09-14 08:43:44,424 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session f46e8b8d-ab39-4063-8a4d-e5aa1deaf1fa is removed.
2015-09-14 08:43:44,430 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 3f68054f-2d31-4f4f-8202-b85dfd188c5a is removed.
2015-09-14 08:43:44,431 INFO: org.apache.tajo.worker.TajoWorker (run(570)) - ============================================
2015-09-14 08:43:44,431 INFO: org.apache.tajo.worker.TajoWorker (run(571)) - TajoWorker received SIGINT Signal
2015-09-14 08:43:44,431 INFO: org.apache.tajo.worker.TajoWorker (run(572)) - ============================================
2015-09-14 08:43:44,434 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf900.gq1.ygridcore.net_29820 stopped.
2015-09-14 08:43:44,436 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-09-14 08:43:44,468 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped.
2015-09-14 08:43:44,469 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped.
2015-09-14 08:43:44,469 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:29822) shutdown
2015-09-14 08:43:44,471 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-09-14 08:43:44,471 INFO: org.apache.tajo.querymaster.QueryMaster (run(425)) - QueryMaster heartbeat thread stopped
2015-09-14 08:43:44,472 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(161)) - QueryMaster stopped
2015-09-14 08:43:44,472 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2015-09-14 08:43:44,473 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:29821) shutdown
2015-09-14 08:43:44,473 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2015-09-14 08:43:44,473 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:29820) shutdown
2015-09-14 08:43:44,474 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-09-14 08:43:44,474 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(380)) - TajoWorker main thread exiting
2015-09-14 08:43:44,474 INFO: org.apache.tajo.rpc.RpcClientManager (close(184)) - Closing RPC client manager
2015-09-14 08:43:45,627 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:34580 to delete [blk_1073748646_7822, blk_1073748647_7823, blk_1073748634_7810, blk_1073748635_7811, blk_1073748636_7812, blk_1073748637_7813]
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]
>
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: 1639, Failures: 4, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.702 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.449 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.997 s]
[INFO] Tajo Common ....................................... SUCCESS [ 30.298 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.269 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.759 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.752 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.181 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 51.690 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.426 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 9.517 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 2.747 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 44.683 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.064 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.572 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.678 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 3.556 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.066 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.748 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.357 s]
[INFO] Tajo Core ......................................... SUCCESS [ 6.441 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.914 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 10.131 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.045 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.948 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.009 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.265 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.200 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [01:04 min]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.933 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.374 s]
[INFO] Tajo Core Tests ................................... FAILURE [22:26 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 27:00 min
[INFO] Finished at: 2015-09-14T08:44:14+00:00
[INFO] Final Memory: 147M/2351M
[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 59221377 bytes
Compression is 0.0%
Took 21 sec
Recording test results
Build failed in Jenkins: Tajo-master-jdk8-nightly #151
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/151/changes>
Changes:
[jihoonson] TAJO-1813: Allow external catalog store for unit testing.
[jhkim] TAJO-1851: Can not release a different rack task.
[blrunner] TAJO-1824: Remove partition_keys table from information_schema.
------------------------------------------
[...truncated 743784 lines...]
2015-09-16 05:20:39,893 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-16 05:20:39,893 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createFullOuterHashJoinPlan(622)) - Full Outer Join (6) chooses [Hash Join]
2015-09-16 05:20:39,893 INFO: org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(80)) - Output data directory: <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/3/0_0/output>
2015-09-16 05:20:39,918 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1442379484131_2118_000003_000000_00] Chunks creation time: 1 msec
2015-09-16 05:20:39,923 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442379484131_2118_000003_000000_00 is changed to TA_SUCCEEDED
2015-09-16 05:20:39,923 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442379484131_2118_000003_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.Stage (transition(1345)) - Stage - eb_1442379484131_2118_000003 finalize RANGE_SHUFFLE (total=1, success=1, killed=0)
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1442379484131_2118_000003 (total=1, success=1, killed=0)
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.Query (handle(851)) - Processing q_1442379484131_2118 of type STAGE_COMPLETED
2015-09-16 05:20:39,924 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1442379484131_2118_000004
2015-09-16 05:20:39,924 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(753)) - Scheduling Stage:eb_1442379484131_2118_000004
2015-09-16 05:20:39,925 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1442379484131_2118_000004
2015-09-16 05:20:39,925 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1442379484131_2118_000003
2015-09-16 05:20:39,925 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1091)) - eb_1442379484131_2118_000004, Table's volume is approximately 1 MB
2015-09-16 05:20:39,925 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1096)) - eb_1442379484131_2118_000004, The determined number of non-leaf tasks is 1
2015-09-16 05:20:39,925 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleRangeShuffledFetches(670)) - eb_1442379484131_2118_000004, Try to divide [(1,1), (5,3)) into 1 sub ranges (total units: 1)
2015-09-16 05:20:39,926 INFO: org.apache.tajo.engine.utils.TupleUtil (setMaxRangeIfNull(104)) - Set null into range: default.orders.o_orderkey, current tuple is (5,NULL)
2015-09-16 05:20:39,926 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1 objects are scheduled
2015-09-16 05:20:39,926 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(131)) - Start TaskScheduler
2015-09-16 05:20:39,928 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf906.gq1.ygridcore.net:34064
2015-09-16 05:20:39,929 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:58233/tajo
2015-09-16 05:20:39,929 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/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir>
2015-09-16 05:20:39,930 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-09-16 05:20:39,930 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/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/4)>
2015-09-16 05:20:39,930 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442379484131_2118_000004_000000_00 is changed to TA_PENDING
2015-09-16 05:20:39,930 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1442379484131_2118_000004_000000_00
2015-09-16 05:20:39,930 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:58233/tmp/tajo-jenkins/staging/q_1442379484131_2118/RESULT/part-04-000000-000
2015-09-16 05:20:39,931 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:58233/tmp/tajo-jenkins/staging/q_1442379484131_2118/RESULT/part-04-000000-000
2015-09-16 05:20:39,931 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-16 05:20:39,931 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442379484131_2118_000004_000000_00 is initialized
2015-09-16 05:20:39,931 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2015-09-16 05:20:39,931 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/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/4/0_0>
2015-09-16 05:20:39,931 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-16 05:20:39,932 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/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/in/eb_1442379484131_2118_000004/0/0/eb_1442379484131_2118_000003>
2015-09-16 05:20:39,932 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-16 05:20:39,932 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-16 05:20:39,932 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=r, sid=3, partId=0, taskIds=[0_0]
2015-09-16 05:20:39,950 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((1,1), (5,NULL)
2015-09-16 05:20:39,950 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/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/3/0_0/output/output> (start=(1,1), end=(5,NULL), last=true)
2015-09-16 05:20:39,950 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk: (start=0, length=49, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/3/0_0/output/output>
2015-09-16 05:20:39,950 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=49, fromRemote=false, ebId=eb_1442379484131_2118_000003) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/3/0_0/output/output>
2015-09-16 05:20:39,950 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442379484131_2118_000004_000000_00 is changed to TA_RUNNING
2015-09-16 05:20:39,950 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-09-16 05:20:39,950 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list
2015-09-16 05:20:39,950 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(362)) - ta_1442379484131_2118_000004_000000_00 All fetches are done!
2015-09-16 05:20:39,951 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-16 05:20:39,952 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1442379484131_2118_000004_000000_00] Total merge time: 0 msec
2015-09-16 05:20:39,953 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (close(791)) - Delete file: "fragment": {"id": "eb_1442379484131_2118_000003", "path": <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/0a455fb2-3ba2-4d27-8e9d-e4b4391fec15/tajo-localdir/q_1442379484131_2118/output/3/0_0/output/output",> "start": 0,"length": 49}
2015-09-16 05:20:39,957 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748642_7818{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-add98999-0f7f-4183-9dfe-4b383e9c7eea:NORMAL:127.0.0.1:51573|FINALIZED]]} size 0
2015-09-16 05:20:39,958 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442379484131_2118_000004_000000_00 is changed to TA_SUCCEEDED
2015-09-16 05:20:39,958 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442379484131_2118_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-16 05:20:39,959 INFO: org.apache.tajo.querymaster.Stage (transition(1345)) - Stage - eb_1442379484131_2118_000004 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-09-16 05:20:39,959 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-16 05:20:39,960 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1442379484131_2118_000004 (total=1, success=1, killed=0)
2015-09-16 05:20:39,960 INFO: org.apache.tajo.querymaster.Query (handle(851)) - Processing q_1442379484131_2118 of type STAGE_COMPLETED
2015-09-16 05:20:39,960 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1442379484131_2118_000005
2015-09-16 05:20:39,960 INFO: org.apache.tajo.querymaster.Query (transition(798)) - Complete Stage[eb_1442379484131_2118_000004], State: SUCCEEDED, 4/4.
2015-09-16 05:20:39,960 INFO: org.apache.tajo.querymaster.Query (handle(851)) - Processing q_1442379484131_2118 of type QUERY_COMPLETED
2015-09-16 05:20:39,961 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1442379484131_2118_000004
2015-09-16 05:20:39,961 INFO: org.apache.tajo.querymaster.Query (handle(869)) - q_1442379484131_2118 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-09-16 05:20:39,961 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(292)) - Query completion notified from q_1442379484131_2118 final state: QUERY_SUCCEEDED
2015-09-16 05:20:39,962 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(253)) - Received QueryMaster heartbeat:q_1442379484131_2118,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf906.gq1.ygridcore.net
2015-09-16 05:20:39,962 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1442379484131_2118
2015-09-16 05:20:39,962 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-16 05:20:39,962 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1442379484131_2118
2015-09-16 05:20:39,962 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(169)) - Stopping QueryMasterTask:q_1442379484131_2118
2015-09-16 05:20:39,963 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(469)) - Cleanup resources of all workers. Query: q_1442379484131_2118, workers: 1
2015-09-16 05:20:39,964 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(185)) - Stopped QueryMasterTask:q_1442379484131_2118
2015-09-16 05:20:39,965 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-16 05:20:40,030 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1
2015-09-16 05:20:40,031 INFO: org.apache.tajo.storage.FileTablespace (getSplits(569)) - Total # of splits: 1
2015-09-16 05:20:40,034 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073748642_7818 127.0.0.1:51573
2015-09-16 05:20:40,034 INFO: org.apache.tajo.master.exec.NonForwardQueryResultFileScanner (close(174)) - "Sent result to client for 32c8fa5c-7690-4bcc-9c18-b277ffd78d52, queryId: q_1442379484131_2118 rows: 5
2015-09-16 05:20:40,035 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(365)) - Saving query summary: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2117/query.hist
2015-09-16 05:20:40,039 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 32c8fa5c-7690-4bcc-9c18-b277ffd78d52 is removed.
2015-09-16 05:20:40,043 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748643_7819{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-9df86e4a-4ead-414b-b7b7-293c7931f087:NORMAL:127.0.0.1:51573|FINALIZED]]} size 0
2015-09-16 05:20:40,044 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session 11cb3bc5-1ce3-491f-b466-25666abc7503 is created.
2015-09-16 05:20:40,045 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2117/eb_1442379484131_2117_000002.hist
2015-09-16 05:20:40,046 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: create table "TEST_DESC_TABLE" (col1 int4, col2 int4)
2015-09-16 05:20:40,046 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-09-16 05:20:40,046 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-16 05:20:40,047 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-09-16 05:20:40,047 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-16 05:20:40,049 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748644_7820{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-add98999-0f7f-4183-9dfe-4b383e9c7eea:NORMAL:127.0.0.1:51573|FINALIZED]]} size 0
2015-09-16 05:20:40,049 INFO: org.apache.tajo.catalog.CatalogServer (createTable(675)) - relation "default.TEST_DESC_TABLE" is added to the catalog (127.0.0.1:34058)
2015-09-16 05:20:40,049 INFO: org.apache.tajo.master.exec.DDLExecutor (create(111)) - relation 'default.TEST_DESC_TABLE' created.
2015-09-16 05:20:40,051 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2117/eb_1442379484131_2117_000001.hist
2015-09-16 05:20:40,054 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748645_7821{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-9df86e4a-4ead-414b-b7b7-293c7931f087:NORMAL:127.0.0.1:51573|RBW]]} size 0
2015-09-16 05:20:40,055 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 11cb3bc5-1ce3-491f-b466-25666abc7503 is removed.
2015-09-16 05:20:40,056 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(365)) - Saving query summary: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2118/query.hist
Tests run: 22, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.514 sec - in org.apache.tajo.cli.tsql.TestTajoCli
2015-09-16 05:20:40,061 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748646_7822{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-add98999-0f7f-4183-9dfe-4b383e9c7eea:NORMAL:127.0.0.1:51573|RBW]]} size 0
2015-09-16 05:20:40,063 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
2015-09-16 05:20:40,065 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
Sep 16, 2015 5:08:33 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:34 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:53 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:53 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:53 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:53 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:53 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Sep 16, 2015 5:08:57 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
2015-09-16 05:20:40,066 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2118/eb_1442379484131_2118_000004.hist
2015-09-16 05:20:40,072 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748647_7823{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-9df86e4a-4ead-414b-b7b7-293c7931f087:NORMAL:127.0.0.1:51573|RBW]]} size 0
2015-09-16 05:20:40,073 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 2d9e0a77-98f1-4280-8d85-c998da7a32e5 is removed.
2015-09-16 05:20:40,075 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2118/eb_1442379484131_2118_000003.hist
2015-09-16 05:20:40,076 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 4879e383-49f6-4c73-b220-39e8c3d016ed is removed.
2015-09-16 05:20:40,078 INFO: org.apache.tajo.worker.TajoWorker (run(570)) - ============================================
2015-09-16 05:20:40,078 INFO: org.apache.tajo.worker.TajoWorker (run(571)) - TajoWorker received SIGINT Signal
2015-09-16 05:20:40,078 INFO: org.apache.tajo.worker.TajoWorker (run(572)) - ============================================
2015-09-16 05:20:40,081 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-09-16 05:20:40,084 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748648_7824{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-add98999-0f7f-4183-9dfe-4b383e9c7eea:NORMAL:127.0.0.1:51573|FINALIZED]]} size 0
2015-09-16 05:20:40,085 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2118/eb_1442379484131_2118_000002.hist
2015-09-16 05:20:40,085 WARN: org.apache.hadoop.hdfs.DFSClient (run(824)) - DFSOutputStream ResponseProcessor exception for block BP-344275308-67.195.81.150-1442379479879:blk_1073748648_7824
java.util.NoSuchElementException
at java.util.LinkedList.getFirst(LinkedList.java:244)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer$ResponseProcessor.run(DFSOutputStream.java:781)
2015-09-16 05:20:40,092 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748649_7825{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-9df86e4a-4ead-414b-b7b7-293c7931f087:NORMAL:127.0.0.1:51573|FINALIZED]]} size 0
2015-09-16 05:20:40,094 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58233/tmp/tajo-jenkins/staging/history/20150916/query-detail/q_1442379484131_2118/eb_1442379484131_2118_000001.hist
2015-09-16 05:20:40,098 ERROR: org.apache.hadoop.hdfs.DFSClient (closeAllFilesBeingWritten(954)) - Failed to close inode 29893
java.io.IOException: All datanodes DatanodeInfoWithStorage[127.0.0.1:51573,DS-9df86e4a-4ead-414b-b7b7-293c7931f087,DISK] are bad. Aborting...
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.setupPipelineForAppendOrRecovery(DFSOutputStream.java:1084)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.processDatanodeError(DFSOutputStream.java:876)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.run(DFSOutputStream.java:402)
2015-09-16 05:20:40,101 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51573 is added to blk_1073748650_7826{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-add98999-0f7f-4183-9dfe-4b383e9c7eea:NORMAL:127.0.0.1:51573|RBW]]} size 0
2015-09-16 05:20:40,102 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf906.gq1.ygridcore.net_34062 stopped.
2015-09-16 05:20:40,127 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped.
2015-09-16 05:20:40,127 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped.
2015-09-16 05:20:40,129 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:34064) shutdown
2015-09-16 05:20:40,130 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-09-16 05:20:40,130 INFO: org.apache.tajo.querymaster.QueryMaster (run(425)) - QueryMaster heartbeat thread stopped
2015-09-16 05:20:40,131 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(161)) - QueryMaster stopped
2015-09-16 05:20:40,131 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2015-09-16 05:20:40,132 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:34063) shutdown
2015-09-16 05:20:40,132 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2015-09-16 05:20:40,132 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:34062) shutdown
2015-09-16 05:20:40,132 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-09-16 05:20:40,132 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(380)) - TajoWorker main thread exiting
2015-09-16 05:20:40,132 INFO: org.apache.tajo.rpc.RpcClientManager (close(184)) - Closing RPC client manager
2015-09-16 05:20:40,331 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:51573 to delete [blk_1073748640_7816, blk_1073748641_7817, blk_1073748642_7818, blk_1073748639_7815]
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]
>
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: 1639, Failures: 4, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 2.209 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.977 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.925 s]
[INFO] Tajo Common ....................................... SUCCESS [ 31.581 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.552 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.000 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.858 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.354 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 49.793 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.475 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 11.360 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 3.058 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 47.324 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.315 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.879 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 2.297 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 4.454 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.186 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 4.178 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.488 s]
[INFO] Tajo Core ......................................... SUCCESS [ 8.097 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.966 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 11.083 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.140 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 1.150 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.067 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.779 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.749 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [01:03 min]
[INFO] Tajo Storage ...................................... SUCCESS [ 1.013 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.644 s]
[INFO] Tajo Core Tests ................................... FAILURE [23:17 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 28:04 min
[INFO] Finished at: 2015-09-16T05:21:10+00:00
[INFO] Final Memory: 148M/1755M
[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 59205911 bytes
Compression is 0.0%
Took 16 sec
Recording test results
Build failed in Jenkins: Tajo-master-jdk8-nightly #150
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/150/changes>
Changes:
[hyunsik] TAJO-1848: ShutdownHook in TajoMaster can throw NPE if serviceInit() is failed.
------------------------------------------
[...truncated 742313 lines...]
=> in schema:{(1) default.lineitem.l_orderkey (INT4)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4)
=> out schema: {(1) default.lineitem.l_orderkey (INT4)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
=======================================================
Block Id: eb_1442355649336_2118_000002 [ROOT]
=======================================================
[Incoming]
[q_1442355649336_2118] 1 => 2 (type=HASH_SHUFFLE, key=default.lineitem.l_orderkey (INT4), num=32)
GROUP_BY(1)(l_orderkey)
=> target list: default.lineitem.l_orderkey (INT4)
=> out schema:{(1) default.lineitem.l_orderkey (INT4)}
=> in schema:{(1) default.lineitem.l_orderkey (INT4)}
SCAN(6) on eb_1442355649336_2118_000001
=> out schema: {(1) default.lineitem.l_orderkey (INT4)}
=> in schema: {(1) default.lineitem.l_orderkey (INT4)}
=======================================================
Block Id: eb_1442355649336_2118_000003 [TERMINAL]
=======================================================
2015-09-15 22:41:54,844 INFO: org.apache.tajo.querymaster.Query (<init>(235)) -
=======================================================
The order of execution:
1: eb_1442355649336_2118_000001
2: eb_1442355649336_2118_000002
3: eb_1442355649336_2118_000003
=======================================================
2015-09-15 22:41:54,845 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58648 is added to blk_1073748644_7820{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-ad47703f-0c82-43f2-96c5-f1b0db2ed27a:NORMAL:127.0.0.1:58648|FINALIZED]]} size 0
2015-09-15 22:41:54,845 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442355649336_2118 of type START
2015-09-15 22:41:54,845 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (first(84)) - Initial executable blocks [eb_1442355649336_2118_000001]
2015-09-15 22:41:54,845 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1442355649336_2118 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2015-09-15 22:41:54,845 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1014)) - eb_1442355649336_2118_000001, Table's volume is approximately 1 MB
2015-09-15 22:41:54,845 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1018)) - eb_1442355649336_2118_000001, The determined number of aggregation partitions is 1
2015-09-15 22:41:54,846 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1442355649336_2118_000001
2015-09-15 22:41:54,846 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:50439/tmp/tajo-jenkins/staging/history/20150915/query-detail/q_1442355649336_2117/eb_1442355649336_2117_000001.hist
2015-09-15 22:41:54,847 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1
2015-09-15 22:41:54,848 INFO: org.apache.tajo.storage.FileTablespace (getSplits(569)) - Total # of splits: 1
2015-09-15 22:41:54,848 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1 objects are scheduled
2015-09-15 22:41:54,848 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(131)) - Start TaskScheduler
2015-09-15 22:41:54,848 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58648 is added to blk_1073748645_7821{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-5ff51e7d-5739-432c-91f0-ce4a664dfcb3:NORMAL:127.0.0.1:58648|FINALIZED]]} size 0
2015-09-15 22:41:54,853 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (increaseConcurrency(521)) - Assigned host : 127.0.0.1, Unknown Volume : -1, Concurrency : 1
2015-09-15 22:41:54,853 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf901.gq1.ygridcore.net:45225
2015-09-15 22:41:54,854 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (assignToLeafTasks(915)) - Assigned Local/Rack/Total: (0/1/1), Attempted Cancel/Assign/Total: (0/1/1), Locality: 0.00%, Rack host: asf901.gq1.ygridcore.net
2015-09-15 22:41:54,853 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:50439/tmp/tajo-jenkins/staging/history/20150915/query-detail/q_1442355649336_2117/eb_1442355649336_2117_000004.hist
2015-09-15 22:41:54,855 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:50439/tajo
2015-09-15 22:41:54,855 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir>
2015-09-15 22:41:54,856 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58648 is added to blk_1073748646_7822{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-ad47703f-0c82-43f2-96c5-f1b0db2ed27a:NORMAL:127.0.0.1:58648|RBW]]} size 0
2015-09-15 22:41:54,856 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:2, vCores:2)
2015-09-15 22:41:54,857 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/output/1)>
2015-09-15 22:41:54,857 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000001_000000_00 is changed to TA_PENDING
2015-09-15 22:41:54,857 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1442355649336_2118_000001_000000_00
2015-09-15 22:41:54,857 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-15 22:41:54,857 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442355649336_2118_000001_000000_00 is initialized
2015-09-15 22:41:54,858 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2015-09-15 22:41:54,858 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/output/1/0_0>
2015-09-15 22:41:54,858 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-15 22:41:54,858 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000001_000000_00 is changed to TA_RUNNING
2015-09-15 22:41:54,858 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1030)) - Aggregation:estimatedSize=604, threshold=67108864
2015-09-15 22:41:54,858 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1032)) - The planner chooses [Hash Aggregation]
2015-09-15 22:41:54,858 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createInMemoryHashAggregation(974)) - The planner chooses [Hash Aggregation]
2015-09-15 22:41:54,862 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000001_000000_00 is changed to TA_SUCCEEDED
2015-09-15 22:41:54,862 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442355649336_2118_000001_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-15 22:41:54,862 INFO: org.apache.tajo.querymaster.Stage (transition(1345)) - Stage - eb_1442355649336_2118_000001 finalize HASH_SHUFFLE (total=1, success=1, killed=0)
2015-09-15 22:41:54,862 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-15 22:41:54,863 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-15 22:41:54,863 INFO: org.apache.tajo.querymaster.Stage (transition(1356)) - eb_1442355649336_2118_000001, wait for HASH_SHUFFLE reports. expected Tasks:1
2015-09-15 22:41:54,863 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(155)) - Close HashShuffleAppender:eb_1442355649336_2118_000001, intermediates=1
2015-09-15 22:41:54,864 INFO: org.apache.tajo.querymaster.Stage (finalizeShuffleReport(1302)) - eb_1442355649336_2118_000001, Finalized HASH_SHUFFLE reports: 1
2015-09-15 22:41:54,864 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1442355649336_2118_000001 (total=1, success=1, killed=0)
2015-09-15 22:41:54,864 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442355649336_2118 of type STAGE_COMPLETED
2015-09-15 22:41:54,864 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1442355649336_2118_000001
2015-09-15 22:41:54,864 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1442355649336_2118_000002
2015-09-15 22:41:54,864 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(757)) - Scheduling Stage:eb_1442355649336_2118_000002
2015-09-15 22:41:54,864 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1442355649336_2118_000002
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1091)) - eb_1442355649336_2118_000002, Table's volume is approximately 1 MB
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1096)) - eb_1442355649336_2118_000002, The determined number of non-leaf tasks is 1
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleHashShuffledFetches(865)) - eb_1442355649336_2118_000002, ScheduleHashShuffledFetches - Max num=1, finalFetchURI=1
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleHashShuffledFetches(885)) - eb_1442355649336_2118_000002, DeterminedTaskNum : 1
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1 objects are scheduled
2015-09-15 22:41:54,865 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(131)) - Start TaskScheduler
2015-09-15 22:41:54,866 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf901.gq1.ygridcore.net:45225
2015-09-15 22:41:54,868 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:50439/tajo
2015-09-15 22:41:54,868 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir>
2015-09-15 22:41:54,868 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-09-15 22:41:54,868 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/output/2)>
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000002_000000_00 is changed to TA_PENDING
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1442355649336_2118_000002_000000_00
2015-09-15 22:41:54,869 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:50439/tmp/tajo-jenkins/staging/q_1442355649336_2118/RESULT/part-02-000000-000
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:50439/tmp/tajo-jenkins/staging/q_1442355649336_2118/RESULT/part-02-000000-000
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442355649336_2118_000002_000000_00 is initialized
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2015-09-15 22:41:54,869 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/output/2/0_0>
2015-09-15 22:41:54,869 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-15 22:41:54,870 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/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/in/eb_1442355649336_2118_000002/0/0/eb_1442355649336_2118_000001>
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=h, sid=1, partId=0, taskIds=null
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=24, fromRemote=false, ebId=eb_1442355649336_2118_000001) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/5d018b2f-9141-4c1d-aaed-23d9d9e0ef5e/tajo-localdir/q_1442355649336_2118/output/1/hash-shuffle/0/0>
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000002_000000_00 is changed to TA_RUNNING
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list
2015-09-15 22:41:54,871 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(362)) - ta_1442355649336_2118_000002_000000_00 All fetches are done!
2015-09-15 22:41:54,872 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-15 22:41:54,872 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1030)) - Aggregation:estimatedSize=24, threshold=67108864
2015-09-15 22:41:54,872 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1032)) - The planner chooses [Hash Aggregation]
2015-09-15 22:41:54,872 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createInMemoryHashAggregation(974)) - The planner chooses [Hash Aggregation]
2015-09-15 22:41:54,876 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58648 is added to blk_1073748647_7823{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-5ff51e7d-5739-432c-91f0-ce4a664dfcb3:NORMAL:127.0.0.1:58648|RBW]]} size 0
2015-09-15 22:41:54,877 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442355649336_2118_000002_000000_00 is changed to TA_SUCCEEDED
2015-09-15 22:41:54,877 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1442355649336_2118_000002_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-15 22:41:54,877 INFO: org.apache.tajo.querymaster.Stage (transition(1345)) - Stage - eb_1442355649336_2118_000002 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-09-15 22:41:54,878 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-15 22:41:54,878 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(123)) - TaskScheduler schedulingThread stopped
2015-09-15 22:41:54,878 INFO: org.apache.tajo.querymaster.Stage (transition(1403)) - Stage completed - eb_1442355649336_2118_000002 (total=1, success=1, killed=0)
2015-09-15 22:41:54,878 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442355649336_2118 of type STAGE_COMPLETED
2015-09-15 22:41:54,878 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1442355649336_2118_000003
2015-09-15 22:41:54,879 INFO: org.apache.tajo.querymaster.Query (transition(802)) - Complete Stage[eb_1442355649336_2118_000002], State: SUCCEEDED, 2/2.
2015-09-15 22:41:54,879 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1442355649336_2118_000002
2015-09-15 22:41:54,879 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442355649336_2118 of type QUERY_COMPLETED
2015-09-15 22:41:54,880 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1442355649336_2118 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-09-15 22:41:54,880 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(292)) - Query completion notified from q_1442355649336_2118 final state: QUERY_SUCCEEDED
2015-09-15 22:41:54,880 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(253)) - Received QueryMaster heartbeat:q_1442355649336_2118,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf901.gq1.ygridcore.net
2015-09-15 22:41:54,880 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(169)) - Stopping QueryMasterTask:q_1442355649336_2118
2015-09-15 22:41:54,880 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1442355649336_2118
2015-09-15 22:41:54,881 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-15 22:41:54,881 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1442355649336_2118
2015-09-15 22:41:54,881 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(469)) - Cleanup resources of all workers. Query: q_1442355649336_2118, workers: 1
2015-09-15 22:41:54,882 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 2eea7be8-a8e7-424e-936f-c83d85a81ad0 is removed.
2015-09-15 22:41:54,882 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(185)) - Stopped QueryMasterTask:q_1442355649336_2118
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.34 sec - in org.apache.tajo.querymaster.TestQueryProgress
Running org.apache.tajo.TestQueryIdFactory
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.TestQueryIdFactory
Running org.apache.tajo.resource.TestResources
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.resource.TestResources
2015-09-15 22:41:54,887 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
2015-09-15 22:41:54,888 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
2015-09-15 22:41:54,900 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 3267bbab-dbae-45c2-9ecb-f4d921ef91da is removed.
2015-09-15 22:41:54,902 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session c13d0d96-ee69-4eb4-b71a-52d5f4fdf0a4 is removed.
2015-09-15 22:41:54,904 INFO: org.apache.tajo.worker.TajoWorker (run(570)) - ============================================
2015-09-15 22:41:54,906 INFO: org.apache.tajo.worker.TajoWorker (run(571)) - TajoWorker received SIGINT Signal
2015-09-15 22:41:54,906 INFO: org.apache.tajo.worker.TajoWorker (run(572)) - ============================================
2015-09-15 22:41:54,908 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf901.gq1.ygridcore.net_45223 stopped.
2015-09-15 22:41:54,910 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-09-15 22:41:54,949 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped.
2015-09-15 22:41:54,951 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped.
2015-09-15 22:41:54,952 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:45225) shutdown
2015-09-15 22:41:54,954 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-09-15 22:41:54,954 INFO: org.apache.tajo.querymaster.QueryMaster (run(425)) - QueryMaster heartbeat thread stopped
2015-09-15 22:41:54,956 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(161)) - QueryMaster stopped
2015-09-15 22:41:54,956 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2015-09-15 22:41:54,957 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:45224) shutdown
2015-09-15 22:41:54,957 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2015-09-15 22:41:54,958 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:45223) shutdown
2015-09-15 22:41:54,958 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-09-15 22:41:54,959 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(380)) - TajoWorker main thread exiting
2015-09-15 22:41:54,959 INFO: org.apache.tajo.rpc.RpcClientManager (close(184)) - Closing RPC client manager
Results :
Failed tests:
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...>
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]
>
Tests run: 1639, Failures: 4, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.561 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.274 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.566 s]
[INFO] Tajo Common ....................................... SUCCESS [ 30.288 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.216 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.766 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.198 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.219 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 51.910 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.416 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 8.972 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 2.499 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 47.663 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 0.905 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.786 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.721 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 3.554 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 1.847 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.779 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.387 s]
[INFO] Tajo Core ......................................... SUCCESS [ 5.712 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.931 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 9.739 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.063 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.967 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.031 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.379 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 1.969 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [01:01 min]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.946 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.308 s]
[INFO] Tajo Core Tests ................................... FAILURE [21:45 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 26:16 min
[INFO] Finished at: 2015-09-15T22:42:25+00:00
[INFO] Final Memory: 149M/2116M
[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 59210463 bytes
Compression is 0.0%
Took 20 sec
Recording test results
Build failed in Jenkins: Tajo-master-jdk8-nightly #149
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/149/changes>
Changes:
[hyunsik] TAJO-1841: Eliminate explicit diamond expressions in tajo-{algebra,rpc}
------------------------------------------
[...truncated 68167 lines...]
2015-09-14 18:32:48,463 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-14 18:32:48,463 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-09-14 18:32:48,463 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-14 18:32:48,468 INFO: org.apache.tajo.catalog.CatalogServer (createTable(671)) - relation "TestInsertQuery.table1" is added to the catalog (127.0.0.1:14126)
2015-09-14 18:32:48,468 INFO: org.apache.tajo.master.exec.DDLExecutor (create(111)) - relation 'TestInsertQuery.table1' created.
2015-09-14 18:32:48,471 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: insert overwrite into table1 select l_orderkey, l_partkey, l_quantity from default.lineitem
2015-09-14 18:32:48,488 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
INSERT(2) INTO TestInsertQuery.table1
=> {(3) TestInsertQuery.table1.col1 (INT4), TestInsertQuery.table1.col2 (INT4), TestInsertQuery.table1.col3 (FLOAT8)}
PROJECTION(1)
=> Targets: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)
=> out schema: {(3) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)
=> out schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
2015-09-14 18:32:48,489 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-14 18:32:48,489 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
INSERT(2) INTO TestInsertQuery.table1
=> {(3) TestInsertQuery.table1.col1 (INT4), TestInsertQuery.table1.col2 (INT4), TestInsertQuery.table1.col3 (FLOAT8)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)
=> out schema: {(3) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
2015-09-14 18:32:48,489 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-14 18:32:48,490 INFO: org.apache.tajo.master.exec.QueryExecutor (executeDistributedQuery(556)) - Query q_1442255323450_0202,insert overwrite into table1 select l_orderkey, l_partkey, l_quantity from default.lineitem, is forwarded to :0
2015-09-14 18:32:48,490 INFO: org.apache.tajo.master.QueryInProgress (connectQueryMaster(184)) - Try to connect to QueryMaster:asf903.gq1.ygridcore.net/67.195.81.147:14132
2015-09-14 18:32:48,491 INFO: org.apache.tajo.master.QueryInProgress (allocateToQueryMaster(163)) - Initializing QueryInProgress for QueryID=q_1442255323450_0202
2015-09-14 18:32:48,491 INFO: org.apache.tajo.master.scheduler.SimpleScheduler (run(384)) - Running Queries: 1
2015-09-14 18:32:48,491 INFO: org.apache.tajo.master.QueryInProgress (submitToQueryMaster(206)) - Call executeQuery to :asf903.gq1.ygridcore.net:14132,q_1442255323450_0202
2015-09-14 18:32:48,493 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (executeQuery(235)) - Receive executeQuery request:q_1442255323450_0202
2015-09-14 18:32:48,494 INFO: org.apache.tajo.querymaster.QueryMaster (handle(361)) - Start QueryStartEventHandler:q_1442255323450_0202
2015-09-14 18:32:48,494 INFO: org.apache.tajo.querymaster.QueryMasterTask (startQuery(314)) - INDEX_ENABLED : false
2015-09-14 18:32:48,724 INFO: org.apache.tajo.querymaster.QueryMasterTask (initStagingDir(390)) - The staging dir 'hdfs://localhost:52650/tajo/warehouse/TestInsertQuery/table1/.staging/q_1442255323450_0202' is created.
2015-09-14 18:32:48,724 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(128)) -
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
INSERT(2) INTO TestInsertQuery.table1
=> {(3) TestInsertQuery.table1.col1 (INT4), TestInsertQuery.table1.col2 (INT4), TestInsertQuery.table1.col3 (FLOAT8)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)
=> out schema: {(3) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
2015-09-14 18:32:48,725 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(157)) -
Non-optimized master plan
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1442255323450_0202_000002)
-------------------------------------------------------------------------------
|-eb_1442255323450_0202_000002
|-eb_1442255323450_0202_000001
-------------------------------------------------------------------------------
Order of Execution
-------------------------------------------------------------------------------
1: eb_1442255323450_0202_000001
2: eb_1442255323450_0202_000002
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1442255323450_0202_000001 [ROOT]
=======================================================
INSERT(2) INTO TestInsertQuery.table1
=> {(3) TestInsertQuery.table1.col1 (INT4), TestInsertQuery.table1.col2 (INT4), TestInsertQuery.table1.col3 (FLOAT8)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)
=> out schema: {(3) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
=======================================================
Block Id: eb_1442255323450_0202_000002 [TERMINAL]
=======================================================
2015-09-14 18:32:48,725 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(160)) -
Optimized master plan
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1442255323450_0202_000002)
-------------------------------------------------------------------------------
|-eb_1442255323450_0202_000002
|-eb_1442255323450_0202_000001
-------------------------------------------------------------------------------
Order of Execution
-------------------------------------------------------------------------------
1: eb_1442255323450_0202_000001
2: eb_1442255323450_0202_000002
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1442255323450_0202_000001 [ROOT]
=======================================================
INSERT(2) INTO TestInsertQuery.table1
=> {(3) TestInsertQuery.table1.col1 (INT4), TestInsertQuery.table1.col2 (INT4), TestInsertQuery.table1.col3 (FLOAT8)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)
=> out schema: {(3) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_quantity (FLOAT8)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
=======================================================
Block Id: eb_1442255323450_0202_000002 [TERMINAL]
=======================================================
2015-09-14 18:32:48,725 INFO: org.apache.tajo.querymaster.Query (<init>(235)) -
=======================================================
The order of execution:
1: eb_1442255323450_0202_000001
2: eb_1442255323450_0202_000002
=======================================================
2015-09-14 18:32:48,726 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1442255323450_0202 of type START
2015-09-14 18:32:48,726 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (first(84)) - Initial executable blocks [eb_1442255323450_0202_000001]
2015-09-14 18:32:48,726 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1442255323450_0202 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2015-09-14 18:32:48,727 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1442255323450_0202_000001
2015-09-14 18:32:48,728 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1
2015-09-14 18:32:48,729 INFO: org.apache.tajo.storage.FileTablespace (getSplits(569)) - Total # of splits: 1
2015-09-14 18:32:48,729 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1 objects are scheduled
2015-09-14 18:32:48,729 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(131)) - Start TaskScheduler
2015-09-14 18:32:48,731 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (increaseConcurrency(521)) - Assigned host : 127.0.0.1, Unknown Volume : -1, Concurrency : 1
2015-09-14 18:32:48,732 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf903.gq1.ygridcore.net:14132
2015-09-14 18:32:48,732 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (assignToLeafTasks(915)) - Assigned Local/Rack/Total: (0/1/1), Attempted Cancel/Assign/Total: (0/1/1), Locality: 0.00%, Rack host: asf903.gq1.ygridcore.net
2015-09-14 18:32:48,734 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:52650/tajo
2015-09-14 18:32:48,734 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/a9ec4ce7-0f2f-4435-a8ba-0bcb0400f205/tajo-localdir>
2015-09-14 18:32:48,735 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:2, vCores:2)
2015-09-14 18:32:48,735 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/a9ec4ce7-0f2f-4435-a8ba-0bcb0400f205/tajo-localdir/q_1442255323450_0202/output/1)>
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442255323450_0202_000001_000000_00 is changed to TA_PENDING
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1442255323450_0202_000001_000000_00
2015-09-14 18:32:48,736 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:52650/tajo/warehouse/TestInsertQuery/table1/.staging/q_1442255323450_0202/RESULT/part-01-000000-000
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:52650/tajo/warehouse/TestInsertQuery/table1/.staging/q_1442255323450_0202/RESULT/part-01-000000-000
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1442255323450_0202_000001_000000_00 is initialized
2015-09-14 18:32:48,736 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:0) :
2015-09-14 18:32:48,736 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/a9ec4ce7-0f2f-4435-a8ba-0bcb0400f205/tajo-localdir/q_1442255323450_0202/output/1/0_0>
2015-09-14 18:32:48,737 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-14 18:32:48,737 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1442255323450_0202_000001_000000_00 is changed to TA_RUNNING
2015-09-14 18:32:48,745 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38667 is added to blk_1073742765_1941{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1a3b321c-7b29-4fd5-bd97-5a91920f0449:NORMAL:127.0.0.1:38667|FINALIZED]]} size 0
Killed
Results :
Tests run: 256, Failures: 0, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 3.388 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 2.489 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.633 s]
[INFO] Tajo Common ....................................... SUCCESS [ 32.354 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.992 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.974 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 8.824 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.448 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 51.249 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.725 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 13.504 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 4.117 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [01:02 min]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.305 s]
[INFO] Tajo Client ....................................... SUCCESS [ 3.165 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 2.284 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 5.224 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.664 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 5.431 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.490 s]
[INFO] Tajo Core ......................................... SUCCESS [ 9.105 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.964 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 17.369 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.073 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 1.001 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.089 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 5.411 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 3.599 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [01:12 min]
[INFO] Tajo Storage ...................................... SUCCESS [ 1.131 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.756 s]
[INFO] Tajo Core Tests ................................... FAILURE [04:17 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 09:51 min
[INFO] Finished at: 2015-09-14T18:32:48+00:00
[INFO] Final Memory: 148M/1631M
[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/surefirebooter1364359627874967902.jar> <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire/surefire2483881019278059152tmp> <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire/surefire_142470529754431335250tmp>
[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 59224552 bytes
Compression is 0.0%
Took 24 sec
Recording test results