See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/160/changes>
Changes:
[hyunsik] TAJO-1867: TajoMaster should handle the change of ${tajo.root}.
------------------------------------------
[...truncated 744200 lines...]
2015-09-18 03:05:25,553 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000003_000000_00 is
changed to TA_PENDING
2015-09-18 03:05:25,553 INFO: org.apache.tajo.worker.TaskImpl (init(195)) -
Initializing: ta_1442544177018_2120_000003_000000_00
2015-09-18 03:05:25,554 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) -
==================================
2015-09-18 03:05:25,554 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) -
* Stage ta_1442544177018_2120_000003_000000_00 is initialized
2015-09-18 03:05:25,554 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) -
* InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 4), Fetches
(total:2) :
2015-09-18 03:05:25,554 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0>
2015-09-18 03:05:25,554 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) -
==================================
2015-09-18 03:05:25,555 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/in/eb_1442544177018_2120_000003/0/0/eb_1442544177018_2120_000002>
2015-09-18 03:05:25,555 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/in/eb_1442544177018_2120_000003/0/0/eb_1442544177018_2120_000001>
2015-09-18 03:05:25,555 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=h,
sid=2, partId=0, taskIds=null
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0,
length=30, fromRemote=false, ebId=eb_1442544177018_2120_000002)
<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/2/hash-shuffle/0/0>
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-18 03:05:25,556 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=h,
sid=1, partId=0, taskIds=null
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0,
length=40, fromRemote=false, ebId=eb_1442544177018_2120_000001)
<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/1/hash-shuffle/0/0>
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000003_000000_00 is
changed to TA_RUNNING
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get
pseudo fetch from local host
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add
a new FileChunk to local chunk list
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get
pseudo fetch from local host
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add
a new FileChunk to local chunk list
2015-09-18 03:05:25,557 INFO: org.apache.tajo.worker.TaskImpl
(waitForFetch(362)) - ta_1442544177018_2120_000003_000000_00 All fetches are
done!
2015-09-18 03:05:25,558 INFO: org.apache.tajo.worker.TaskImpl
(localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-18 03:05:25,558 INFO: org.apache.tajo.worker.TaskImpl
(localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-18 03:05:25,558 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(createFullOuterHashJoinPlan(622)) - Full Outer Join (6) chooses [Hash Join]
2015-09-18 03:05:25,559 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0/output>
2015-09-18 03:05:25,581 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) -
[ta_1442544177018_2120_000003_000000_00] Chunks creation time: 1 msec
2015-09-18 03:05:25,586 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000003_000000_00 is
changed to TA_SUCCEEDED
2015-09-18 03:05:25,586 INFO: org.apache.tajo.worker.TaskImpl (run(460)) -
ta_1442544177018_2120_000003_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2015-09-18 03:05:25,587 INFO: org.apache.tajo.querymaster.Stage
(transition(1345)) - Stage - eb_1442544177018_2120_000003 finalize
RANGE_SHUFFLE (total=1, success=1, killed=0)
2015-09-18 03:05:25,587 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(stop(160)) - Task Scheduler stopped
2015-09-18 03:05:25,587 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(run(123)) - TaskScheduler schedulingThread stopped
2015-09-18 03:05:25,587 INFO: org.apache.tajo.querymaster.Stage
(transition(1403)) - Stage completed - eb_1442544177018_2120_000003 (total=1,
success=1, killed=0)
2015-09-18 03:05:25,587 INFO: org.apache.tajo.querymaster.Query (handle(851)) -
Processing q_1442544177018_2120 of type STAGE_COMPLETED
2015-09-18 03:05:25,587 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next
executable block eb_1442544177018_2120_000004
2015-09-18 03:05:25,588 INFO: org.apache.tajo.querymaster.Query
(executeNextBlock(753)) - Scheduling Stage:eb_1442544177018_2120_000004
2015-09-18 03:05:25,588 INFO: org.apache.tajo.worker.TaskManager
(stopExecutionBlock(161)) - Stopped execution block:eb_1442544177018_2120_000003
2015-09-18 03:05:25,588 INFO: org.apache.tajo.querymaster.Stage
(initTaskScheduler(897)) - org.apache.tajo.querymaster.DefaultTaskScheduler is
chosen for the task scheduling for eb_1442544177018_2120_000004
2015-09-18 03:05:25,588 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1091)) - eb_1442544177018_2120_000004, Table's volume is
approximately 1 MB
2015-09-18 03:05:25,588 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1096)) - eb_1442544177018_2120_000004, The determined number
of non-leaf tasks is 1
2015-09-18 03:05:25,589 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleRangeShuffledFetches(673)) - eb_1442544177018_2120_000004, Try to
divide [(1,1), (5,3)) into 1 sub ranges (total units: 1)
2015-09-18 03:05:25,589 INFO: org.apache.tajo.engine.utils.TupleUtil
(setMaxRangeIfNull(104)) - Set null into range: default.orders.o_orderkey,
current tuple is (5,NULL)
2015-09-18 03:05:25,589 INFO: org.apache.tajo.querymaster.Stage (run(849)) - 1
objects are scheduled
2015-09-18 03:05:25,589 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(start(131)) - Start TaskScheduler
2015-09-18 03:05:25,591 INFO: org.apache.tajo.worker.TaskManager
(createExecutionBlock(112)) - QueryMaster Address:asf906.gq1.ygridcore.net:13792
2015-09-18 03:05:25,592 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(119)) - Tajo Root Dir: hdfs://localhost:38922/tajo
2015-09-18 03:05:25,592 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir>
2015-09-18 03:05:25,593 INFO: org.apache.tajo.worker.TaskManager (handle(182))
- Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000,
Disks:3, vCores:2)
2015-09-18 03:05:25,593 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/4)>
2015-09-18 03:05:25,593 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000004_000000_00 is
changed to TA_PENDING
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (init(195)) -
Initializing: ta_1442544177018_2120_000004_000000_00
2015-09-18 03:05:25,594 INFO: org.apache.tajo.storage.FileTablespace
(getAppenderFilePath(291)) - Output File Path:
hdfs://localhost:38922/tmp/tajo-jenkins/staging/q_1442544177018_2120/RESULT/part-04-000000-000
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) -
Output File Path:
hdfs://localhost:38922/tmp/tajo-jenkins/staging/q_1442544177018_2120/RESULT/part-04-000000-000
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) -
==================================
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) -
* Stage ta_1442544177018_2120_000004_000000_00 is initialized
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) -
* InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2015-09-18 03:05:25,594 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/4/0_0>
2015-09-18 03:05:25,594 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) -
==================================
2015-09-18 03:05:25,595 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/in/eb_1442544177018_2120_000004/0/0/eb_1442544177018_2120_000003>
2015-09-18 03:05:25,595 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-18 03:05:25,596 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-18 03:05:25,596 INFO: org.apache.tajo.worker.TaskImpl
(getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=r,
sid=3, partId=0, taskIds=[0_0]
2015-09-18 03:05:25,614 INFO: org.apache.tajo.pullserver.TajoPullServerService
(getFileChunks(686)) - BSTIndex is loaded from disk ((1,1), (5,NULL)
2015-09-18 03:05:25,614 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0/output/output>
(start=(1,1), end=(5,NULL), last=true)
2015-09-18 03:05:25,615 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/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0/output/output>
2015-09-18 03:05:25,615 INFO: org.apache.tajo.worker.TaskImpl
(getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0,
length=49, fromRemote=false, ebId=eb_1442544177018_2120_000003)
<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0/output/output>
2015-09-18 03:05:25,615 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000004_000000_00 is
changed to TA_RUNNING
2015-09-18 03:05:25,615 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get
pseudo fetch from local host
2015-09-18 03:05:25,615 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add
a new FileChunk to local chunk list
2015-09-18 03:05:25,615 INFO: org.apache.tajo.worker.TaskImpl
(waitForFetch(362)) - ta_1442544177018_2120_000004_000000_00 All fetches are
done!
2015-09-18 03:05:25,616 INFO: org.apache.tajo.worker.TaskImpl
(localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-18 03:05:25,617 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) -
[ta_1442544177018_2120_000004_000000_00] Total merge time: 0 msec
2015-09-18 03:05:25,618 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (close(791)) - Delete
file: "fragment": {"id": "eb_1442544177018_2120_000003", "path":
<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/973af366-2e53-4ca6-b80b-7f63a06f8d24/tajo-localdir/q_1442544177018_2120/output/3/0_0/output/output";,>
"start": 0,"length": 49}
2015-09-18 03:05:25,621 INFO: BlockStateChange (logAddStoredBlock(2624)) -
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:56414 is added to
blk_1073748647_7823{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-2ec9bbaa-a337-47ff-b431-c8e59687f2ad:NORMAL:127.0.0.1:56414|FINALIZED]]}
size 0
2015-09-18 03:05:25,622 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1442544177018_2120_000004_000000_00 is
changed to TA_SUCCEEDED
2015-09-18 03:05:25,622 INFO: org.apache.tajo.worker.TaskImpl (run(460)) -
ta_1442544177018_2120_000004_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2015-09-18 03:05:25,623 INFO: org.apache.tajo.querymaster.Stage
(transition(1345)) - Stage - eb_1442544177018_2120_000004 finalize NONE_SHUFFLE
(total=1, success=1, killed=0)
2015-09-18 03:05:25,623 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(stop(160)) - Task Scheduler stopped
2015-09-18 03:05:25,623 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(run(123)) - TaskScheduler schedulingThread stopped
2015-09-18 03:05:25,623 INFO: org.apache.tajo.querymaster.Stage
(transition(1403)) - Stage completed - eb_1442544177018_2120_000004 (total=1,
success=1, killed=0)
2015-09-18 03:05:25,624 INFO: org.apache.tajo.querymaster.Query (handle(851)) -
Processing q_1442544177018_2120 of type STAGE_COMPLETED
2015-09-18 03:05:25,624 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next
executable block eb_1442544177018_2120_000005
2015-09-18 03:05:25,624 INFO: org.apache.tajo.querymaster.Query
(transition(798)) - Complete Stage[eb_1442544177018_2120_000004], State:
SUCCEEDED, 4/4.
2015-09-18 03:05:25,624 INFO: org.apache.tajo.querymaster.Query (handle(851)) -
Processing q_1442544177018_2120 of type QUERY_COMPLETED
2015-09-18 03:05:25,624 INFO: org.apache.tajo.worker.TaskManager
(stopExecutionBlock(161)) - Stopped execution block:eb_1442544177018_2120_000004
2015-09-18 03:05:25,625 INFO: org.apache.tajo.querymaster.Query (handle(869)) -
q_1442544177018_2120 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-09-18 03:05:25,625 INFO: org.apache.tajo.querymaster.QueryMasterTask
(handle(292)) - Query completion notified from q_1442544177018_2120 final
state: QUERY_SUCCEEDED
2015-09-18 03:05:25,626 INFO: org.apache.tajo.master.QueryInProgress
(heartbeat(253)) - Received QueryMaster
heartbeat:q_1442544177018_2120,state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=asf906.gq1.ygridcore.net
2015-09-18 03:05:25,626 INFO: org.apache.tajo.master.QueryManager
(stopQuery(279)) - Stop QueryInProgress:q_1442544177018_2120
2015-09-18 03:05:25,626 INFO: org.apache.tajo.master.QueryInProgress
(stopProgress(118)) - =========================================================
2015-09-18 03:05:25,626 INFO: org.apache.tajo.master.QueryInProgress
(stopProgress(119)) - Stop query:q_1442544177018_2120
2015-09-18 03:05:25,626 INFO: org.apache.tajo.querymaster.QueryMasterTask
(serviceStop(169)) - Stopping QueryMasterTask:q_1442544177018_2120
2015-09-18 03:05:25,626 INFO: org.apache.tajo.querymaster.QueryMasterTask
(cleanupQuery(469)) - Cleanup resources of all workers. Query:
q_1442544177018_2120, workers: 1
2015-09-18 03:05:25,626 INFO: org.apache.tajo.querymaster.QueryMasterTask
(serviceStop(185)) - Stopped QueryMasterTask:q_1442544177018_2120
2015-09-18 03:05:25,723 INFO: org.apache.tajo.storage.FileTablespace
(listStatus(365)) - Total input paths to process : 1
2015-09-18 03:05:25,725 INFO: org.apache.tajo.storage.FileTablespace
(getSplits(566)) - Total # of splits: 1
2015-09-18 03:05:25,729 INFO: BlockStateChange (addToInvalidates(1106)) -
BLOCK* addToInvalidates: blk_1073748647_7823 127.0.0.1:56414
2015-09-18 03:05:25,729 INFO:
org.apache.tajo.master.exec.NonForwardQueryResultFileScanner (close(174)) -
"Sent result to client for f61e9afe-c51d-4ca8-a14e-40fb1f5269df, queryId:
q_1442544177018_2120 rows: 5
2015-09-18 03:05:25,731 INFO: org.apache.tajo.session.SessionManager
(removeSession(86)) - Session f61e9afe-c51d-4ca8-a14e-40fb1f5269df is removed.
2015-09-18 03:05:25,736 INFO: org.apache.tajo.session.SessionManager
(createSession(80)) - Session 35fa15fd-8fd5-494b-b182-b5a7c3011b3e is created.
2015-09-18 03:05:25,738 INFO: org.apache.tajo.master.GlobalEngine
(executeQuery(176)) - Query: create table "TEST_DESC_TABLE" (col1 int4, col2
int4)
2015-09-18 03:05:25,739 INFO: org.apache.tajo.master.GlobalEngine
(createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-09-18 03:05:25,739 INFO: org.apache.tajo.master.GlobalEngine
(createLogicalPlan(282)) - =============================================
2015-09-18 03:05:25,739 INFO: org.apache.tajo.master.GlobalEngine
(createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-09-18 03:05:25,739 INFO: org.apache.tajo.master.GlobalEngine
(createLogicalPlan(284)) - =============================================
2015-09-18 03:05:25,742 INFO: org.apache.tajo.catalog.CatalogServer
(createTable(686)) - relation "default.TEST_DESC_TABLE" is added to the catalog
(127.0.0.1:13786)
2015-09-18 03:05:25,742 INFO: org.apache.tajo.master.exec.DDLExecutor
(create(111)) - relation 'default.TEST_DESC_TABLE' created.
2015-09-18 03:05:25,747 INFO: org.apache.tajo.session.SessionManager
(removeSession(86)) - Session 35fa15fd-8fd5-494b-b182-b5a7c3011b3e is removed.
Tests run: 22, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.505 sec - in
org.apache.tajo.cli.tsql.TestTajoCli
2015-09-18 03:05:25,753 INFO: org.mortbay.log (info(67)) - Shutdown hook
executing
2015-09-18 03:05:25,753 INFO: org.mortbay.log (info(67)) - Shutdown hook
complete
Sep 18, 2015 2:53:40 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:53:41 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:01 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:01 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:01 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:02 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:02 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Sep 18, 2015 2:54:04 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
2015-09-18 03:05:25,763 INFO: org.apache.tajo.session.SessionManager
(removeSession(86)) - Session f0e2db09-c20f-4e47-8642-34432f1156d4 is removed.
2015-09-18 03:05:25,765 INFO: org.apache.tajo.session.SessionManager
(removeSession(86)) - Session b9fa17a3-0cae-43f1-a71e-3d038f1fd312 is removed.
2015-09-18 03:05:25,767 INFO: org.apache.tajo.worker.TajoWorker (run(570)) -
============================================
2015-09-18 03:05:25,767 INFO: org.apache.tajo.worker.TajoWorker (run(571)) -
TajoWorker received SIGINT Signal
2015-09-18 03:05:25,767 INFO: org.apache.tajo.worker.TajoWorker (run(572)) -
============================================
2015-09-18 03:05:25,770 INFO: org.apache.tajo.util.history.HistoryWriter
(run(275)) - HistoryWriter_asf906.gq1.ygridcore.net_13790 stopped.
2015-09-18 03:05:25,770 INFO: org.apache.tajo.util.history.HistoryCleaner
(run(136)) - History cleaner stopped
2015-09-18 03:05:25,801 INFO: org.apache.tajo.worker.NodeStatusUpdater
(serviceStop(111)) - NodeStatusUpdater stopped.
2015-09-18 03:05:25,801 INFO: org.apache.tajo.worker.NodeStatusUpdater
(run(262)) - Heartbeat Thread stopped.
2015-09-18 03:05:25,801 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:13792)
shutdown
2015-09-18 03:05:25,803 INFO:
org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) -
QueryMasterManagerService stopped
2015-09-18 03:05:25,804 INFO: org.apache.tajo.querymaster.QueryMaster
(run(425)) - QueryMaster heartbeat thread stopped
2015-09-18 03:05:25,804 INFO: org.apache.tajo.querymaster.QueryMaster
(serviceStop(161)) - QueryMaster stopped
2015-09-18 03:05:25,804 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(98)) - TajoWorkerClientService stopping
2015-09-18 03:05:25,805 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on
0:0:0:0:0:0:0:0:13791) shutdown
2015-09-18 03:05:25,805 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(102)) - TajoWorkerClientService stopped
2015-09-18 03:05:25,805 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:13790)
shutdown
2015-09-18 03:05:25,806 INFO: org.apache.tajo.worker.TajoWorkerManagerService
(serviceStop(93)) - TajoWorkerManagerService stopped
2015-09-18 03:05:25,806 INFO: org.apache.tajo.worker.TajoWorker
(serviceStop(380)) - TajoWorker main thread exiting
2015-09-18 03:05:25,806 INFO: org.apache.tajo.rpc.RpcClientManager (close(184))
- Closing RPC client manager
2015-09-18 03:05:27,296 INFO: BlockStateChange (invalidateWorkForOneNode(3488))
- BLOCK* BlockManager: ask 127.0.0.1:56414 to delete [blk_1073748641_7817,
blk_1073748642_7818, blk_1073748643_7819, blk_1073748647_7823]
Results :
Failed tests:
TestUnionQuery.testUnionAndFilter:698->QueryTestCaseBase.runSimpleTests:617
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: 1640, Failures: 4, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.582 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.378 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.687 s]
[INFO] Tajo Common ....................................... SUCCESS [ 27.554 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.223 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.579 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.150 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.204 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 48.602 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.427 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 10.386 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 2.537 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 47.794 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.108 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.495 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.813 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 3.612 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 1.815 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.582 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.367 s]
[INFO] Tajo Core ......................................... SUCCESS [ 5.744 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.905 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 10.092 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.044 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.954 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.004 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.145 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.209 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [01:01 min]
[INFO] Tajo JDBC storage common .......................... SUCCESS [ 0.816 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.957 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.410 s]
[INFO] Tajo Core Tests ................................... FAILURE [23:10 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 27:37 min
[INFO] Finished at: 2015-09-18T03:05:56+00:00
[INFO] Final Memory: 149M/1902M
[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 59653768 bytes
Compression is 0.0%
Took 16 sec
Recording test results
