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
