See <https://builds.apache.org/job/Tajo-master-build/222/>
------------------------------------------
[...truncated 92750 lines...]
=> 0:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=17.0
=> 1:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=36.0
=> 2:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=38.0
=> 3:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=45.0
=> 4:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=49.0
PARTITIONS_SCAN(10) on default.columnpartitionedtable
=> target list: default.a.col1 (INT4), default.a.col2 (INT4),
default.a.key (FLOAT8)
=> num of filtered paths: 2
=> out schema: {(3) default.a.col1 (INT4),default.a.col2
(INT4),default.a.key (FLOAT8)}
=> in schema: {(2) default.a.col1 (INT4),default.a.col2 (INT4)}
=> 0:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=38.0
=> 1:
hdfs://localhost:52816/tajo/warehouse/default/columnpartitionedtable/key=45.0
=======================================================
Block Id: eb_1400880522585_0296_000004 [ROOT]
=======================================================
[Incoming]
[q_1400880522585_0296] 3 => 4 (type=RANGE_SHUFFLE, key=default.test.col1
(INT4), default.test.col2 (INT4), num=32)
[Enforcers]
0:
PROJECTION(7)
=> Targets: default.test.col1 (INT4), default.test.col2 (INT4),
default.test.key (FLOAT8)
=> out schema: {(3) default.test.col1 (INT4),default.test.col2
(INT4),default.test.key (FLOAT8)}
=> in schema: {(3) default.test.col1 (INT4),default.test.col2
(INT4),default.test.key (FLOAT8)}
SORT(6)
=> Sort Keys: col1 asc,col2 asc
SCAN(14) on eb_1400880522585_0296_000003
=> out schema: {(3) default.test.col1 (INT4),default.test.col2
(INT4),default.test.key (FLOAT8)}
=> in schema: {(3) default.test.col1 (INT4),default.test.col2
(INT4),default.test.key (FLOAT8)}
=======================================================
Block Id: eb_1400880522585_0296_000005 [TERMINAL]
=======================================================
2014-05-23 21:32:59,656 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(start(101)) - AsyncDispatcher started:q_1400880522585_0296
2014-05-23 21:32:59,656 INFO: org.apache.tajo.master.querymaster.Query
(handle(682)) - Processing q_1400880522585_0296 of type START
2014-05-23 21:32:59,657 INFO: org.apache.tajo.master.querymaster.SubQuery
(calculateShuffleOutputNum(797)) - ============>>>>> Unexpected Case!
<<<<<================
2014-05-23 21:32:59,657 INFO: org.apache.tajo.master.querymaster.SubQuery
(calculateShuffleOutputNum(801)) - eb_1400880522585_0296_000003, Table's volume
is approximately 1 MB
2014-05-23 21:32:59,657 INFO: org.apache.tajo.master.querymaster.SubQuery
(calculateShuffleOutputNum(804)) - eb_1400880522585_0296_000003, The determined
number of partitions is 1
2014-05-23 21:32:59,657 INFO: org.apache.tajo.master.querymaster.SubQuery
(initTaskScheduler(677)) - org.apache.tajo.master.DefaultTaskScheduler is
chosen for the task scheduling for eb_1400880522585_0296_000003
2014-05-23 21:32:59,659 INFO: org.apache.tajo.storage.AbstractStorageManager
(listStatus(386)) - Total input paths to process : 5
2014-05-23 21:32:59,659 INFO: org.apache.tajo.storage.AbstractStorageManager
(getSplits(615)) - Total # of splits: 5
2014-05-23 21:32:59,661 INFO: org.apache.tajo.storage.AbstractStorageManager
(listStatus(386)) - Total input paths to process : 5
2014-05-23 21:32:59,661 INFO: org.apache.tajo.storage.AbstractStorageManager
(getSplits(615)) - Total # of splits: 5
2014-05-23 21:32:59,661 INFO: org.apache.tajo.master.querymaster.Repartitioner
(scheduleFragmentsForJoinQuery(142)) - [Distributed Join Strategy] : Immediate
2 Way Join on Single Machine
2014-05-23 21:32:59,661 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(647)) - 1 objects are scheduled
2014-05-23 21:32:59,662 INFO: org.apache.tajo.master.DefaultTaskScheduler
(start(88)) - Start TaskScheduler
2014-05-23 21:32:59,662 INFO: org.apache.tajo.worker.TajoResourceAllocator
(calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number
of Tasks=1, Number of Cluster Slots=1
2014-05-23 21:32:59,662 INFO: org.apache.tajo.master.querymaster.SubQuery
(allocateContainers(884)) - Request Container for eb_1400880522585_0296_000003
containers=1
2014-05-23 21:32:59,662 INFO: org.apache.tajo.master.querymaster.Query
(handle(699)) - q_1400880522585_0296 Query Transitioned from QUERY_NEW to
QUERY_RUNNING
2014-05-23 21:32:59,662 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(217)) - Start TajoWorkerAllocationThread
2014-05-23 21:32:59,663 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(336)) - Stop TajoWorkerAllocationThread
2014-05-23 21:32:59,663 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(992)) - SubQuery (eb_1400880522585_0296_000003) has 1 containers!
2014-05-23 21:32:59,664 INFO: org.apache.tajo.worker.TaskRunner (<init>(123)) -
Tajo Root Dir: hdfs://localhost:52816/tajo
2014-05-23 21:32:59,664 INFO: org.apache.tajo.worker.TaskRunner (<init>(124)) -
Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir>
2014-05-23 21:32:59,664 INFO: org.apache.tajo.worker.TaskRunner (<init>(138)) -
QueryMaster Address:asf001.sp2.ygridcore.net/67.195.138.31:25210
2014-05-23 21:32:59,665 INFO: org.apache.tajo.worker.TaskRunnerManager
(run(188)) - Start
TaskRunner:eb_1400880522585_0296_000003,container_1400880522585_0296_01_001053
2014-05-23 21:32:59,665 INFO: org.apache.tajo.worker.TaskRunner (init(185)) -
TaskRunner basedir is created (q_1400880522585_0296/output/3)
2014-05-23 21:32:59,666 INFO: org.apache.tajo.worker.TaskRunner (run(312)) -
TaskRunner startup
2014-05-23 21:32:59,666 INFO: org.apache.tajo.worker.TaskRunner (run(332)) -
Request GetTask:
eb_1400880522585_0296_000003,container_1400880522585_0296_01_001053
2014-05-23 21:32:59,667 INFO: org.apache.tajo.master.DefaultTaskScheduler
(assignToLeafTasks(798)) - Assigned Local/Remote/Total: (0/1/1), Locality:
0.00%,
2014-05-23 21:32:59,668 INFO: org.apache.tajo.worker.TaskRunner (run(370)) -
Accumulated Received Task: 1
2014-05-23 21:32:59,669 INFO: org.apache.tajo.worker.TaskRunner (run(379)) -
Initializing: ta_1400880522585_0296_000003_000000_00
2014-05-23 21:32:59,684 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000003_000000_00 is
changed to TA_PENDING
2014-05-23 21:32:59,684 INFO: org.apache.tajo.worker.Task (<init>(186)) -
==================================
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(187)) - *
Subquery ta_1400880522585_0296_000003_000000_00 is initialized
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(188)) - *
InterQuery: true, Use RANGE_SHUFFLE shuffle
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(191)) - *
Fragments (num: 1)
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(192)) - *
Fetches (total:0) :
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(196)) - *
Local task dir:
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output/3/0_0>
2014-05-23 21:32:59,685 INFO: org.apache.tajo.worker.Task (<init>(201)) -
==================================
2014-05-23 21:32:59,686 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000003_000000_00 is
changed to TA_RUNNING
2014-05-23 21:32:59,690 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(checkIfInMemoryInnerJoinIsPossible(256)) -
[ta_1400880522585_0296_000003_000000_00] the volume of Left relations
(default.columnpartitionedtable) is 0 B and is fit to main maemory.
2014-05-23 21:32:59,690 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(createBestInnerJoinPlan(409)) - Join (9) chooses [In-memory Hash Join]
2014-05-23 21:32:59,690 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(switchJoinSidesIfNecessary(380)) - [ta_1400880522585_0296_000003_000000_00]
Left relations default.columnpartitionedtable (0 B) is smaller than Right
relations default.columnpartitionedtable (0 B).
2014-05-23 21:32:59,698 INFO:
org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(76)) -
Output data directory:
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output/3/0_0/output>
2014-05-23 21:32:59,735 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(61)) -
[ta_1400880522585_0296_000003_000000_00] Chunks creation time: 13 msec
2014-05-23 21:32:59,742 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000003_000000_00 is
changed to TA_SUCCEEDED
2014-05-23 21:32:59,742 INFO: org.apache.tajo.worker.Task (run(450)) - Worker's
task counter - total:698, succeeded: 694, killed: 4, failed: 0
2014-05-23 21:32:59,742 INFO: org.apache.tajo.worker.TaskRunner (run(332)) -
Request GetTask:
eb_1400880522585_0296_000003,container_1400880522585_0296_01_001053
2014-05-23 21:32:59,742 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1069)) - [eb_1400880522585_0296_000003] Task Completion Event
(Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-05-23 21:32:59,743 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1109)) - subQuery completed - eb_1400880522585_0296_000003
(total=1, success=1, killed=0)
2014-05-23 21:32:59,743 INFO: org.apache.tajo.master.DefaultTaskScheduler
(run(103)) - TaskScheduler schedulingThread stopped
2014-05-23 21:32:59,743 INFO: org.apache.tajo.master.DefaultTaskScheduler
(stop(144)) - Task Scheduler stopped
2014-05-23 21:32:59,743 INFO: org.apache.tajo.worker.TaskRunner (run(362)) -
Received ShouldDie
flag:eb_1400880522585_0296_000003,container_1400880522585_0296_01_001053
2014-05-23 21:32:59,743 INFO: org.apache.tajo.worker.TaskRunner (stop(227)) -
Stop TaskRunner: eb_1400880522585_0296_000003
2014-05-23 21:32:59,743 INFO: org.apache.tajo.worker.TaskRunnerManager
(stopTask(89)) - Stop
Task:eb_1400880522585_0296_000003,container_1400880522585_0296_01_001053
2014-05-23 21:32:59,743 INFO: org.apache.tajo.master.querymaster.Query
(handle(682)) - Processing q_1400880522585_0296 of type SUBQUERY_COMPLETED
2014-05-23 21:32:59,744 INFO: org.apache.tajo.master.querymaster.SubQuery
(initTaskScheduler(677)) - org.apache.tajo.master.DefaultTaskScheduler is
chosen for the task scheduling for eb_1400880522585_0296_000004
2014-05-23 21:32:59,744 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(518)) - Release Resource: 0.5,512
2014-05-23 21:32:59,744 INFO: org.apache.tajo.master.querymaster.SubQuery
(getNonLeafTaskNum(833)) - Table's volume is approximately 1 MB
2014-05-23 21:32:59,744 INFO: org.apache.tajo.master.querymaster.SubQuery
(getNonLeafTaskNum(836)) - The determined number of non-leaf tasks is 1
2014-05-23 21:32:59,745 INFO: org.apache.tajo.master.querymaster.Repartitioner
(scheduleRangeShuffledFetches(384)) - Try to divide [(0=>2, 1=>2), (0=>3,
1=>2)) into 1 sub ranges (total units: 1)
2014-05-23 21:32:59,745 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(647)) - 1 objects are scheduled
2014-05-23 21:32:59,745 INFO: org.apache.tajo.master.DefaultTaskScheduler
(start(88)) - Start TaskScheduler
2014-05-23 21:32:59,745 INFO: org.apache.tajo.worker.TajoResourceAllocator
(calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number
of Tasks=1, Number of Cluster Slots=1
2014-05-23 21:32:59,746 INFO: org.apache.tajo.master.querymaster.SubQuery
(allocateContainers(884)) - Request Container for eb_1400880522585_0296_000004
containers=1
2014-05-23 21:32:59,746 INFO: org.apache.tajo.master.querymaster.Query
(executeNextBlock(603)) - Scheduling SubQuery:eb_1400880522585_0296_000004
2014-05-23 21:32:59,746 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(217)) - Start TajoWorkerAllocationThread
2014-05-23 21:32:59,747 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(336)) - Stop TajoWorkerAllocationThread
2014-05-23 21:32:59,747 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(992)) - SubQuery (eb_1400880522585_0296_000004) has 1 containers!
2014-05-23 21:32:59,748 INFO: org.apache.tajo.worker.TaskRunner (<init>(123)) -
Tajo Root Dir: hdfs://localhost:52816/tajo
2014-05-23 21:32:59,748 INFO: org.apache.tajo.worker.TaskRunner (<init>(124)) -
Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir>
2014-05-23 21:32:59,748 INFO: org.apache.tajo.worker.TaskRunner (<init>(138)) -
QueryMaster Address:asf001.sp2.ygridcore.net/67.195.138.31:25210
2014-05-23 21:32:59,748 INFO: org.apache.tajo.worker.TaskRunnerManager
(run(188)) - Start
TaskRunner:eb_1400880522585_0296_000004,container_1400880522585_0296_01_001054
2014-05-23 21:32:59,749 INFO: org.apache.tajo.worker.TaskRunner (init(185)) -
TaskRunner basedir is created (q_1400880522585_0296/output/4)
2014-05-23 21:32:59,749 INFO: org.apache.tajo.worker.TaskRunner (run(312)) -
TaskRunner startup
2014-05-23 21:32:59,749 INFO: org.apache.tajo.worker.TaskRunner (run(332)) -
Request GetTask:
eb_1400880522585_0296_000004,container_1400880522585_0296_01_001054
2014-05-23 21:32:59,751 INFO: org.apache.tajo.worker.TaskRunner (run(370)) -
Accumulated Received Task: 1
2014-05-23 21:32:59,751 INFO: org.apache.tajo.worker.TaskRunner (run(379)) -
Initializing: ta_1400880522585_0296_000004_000000_00
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(181)) -
Output File Path:
hdfs://localhost:52816/tmp/tajo-jenkins/staging/q_1400880522585_0296/RESULT/part-04-000000
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000004_000000_00 is
changed to TA_PENDING
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(186)) -
==================================
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(187)) - *
Subquery ta_1400880522585_0296_000004_000000_00 is initialized
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(188)) - *
InterQuery: false
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(191)) - *
Fragments (num: 1)
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(192)) - *
Fetches (total:1) :
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(194)) - Table
Id: eb_1400880522585_0296_000003, Simple URIs:
[http://67.195.138.31:56620/?qid=q_1400880522585_0296&sid=3&p=0&type=r&start=AAAAAAIAAAAC&end=AAAAAAMAAAAC&final=true]
2014-05-23 21:32:59,752 INFO: org.apache.tajo.worker.Task (<init>(196)) - *
Local task dir:
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output/4/0_0>
2014-05-23 21:32:59,753 INFO: org.apache.tajo.worker.Task (<init>(201)) -
==================================
2014-05-23 21:32:59,754 INFO: org.apache.tajo.worker.Task (init(217)) - the
directory is created
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/in/eb_1400880522585_0296_000004/0/0/eb_1400880522585_0296_000003>
2014-05-23 21:32:59,756 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000004_000000_00 is
changed to TA_RUNNING
2014-05-23 21:32:59,756 INFO: org.apache.tajo.pullserver.TajoPullServerService
(channelOpen(349)) - Current number of shuffle connections (2)
2014-05-23 21:32:59,757 INFO: org.apache.tajo.worker.Fetcher (get(129)) -
Fetch:
http://67.195.138.31:56620/?qid=q_1400880522585_0296&sid=3&p=0&type=r&start=AAAAAAIAAAAC&end=AAAAAAMAAAAC&final=true&ta=0_0
2014-05-23 21:32:59,757 INFO: org.apache.tajo.pullserver.TajoPullServerService
(messageReceived(394)) - PullServer request param: shuffleType=r, sid=3,
partId=0, taskIds=[0_0]
2014-05-23 21:32:59,757 INFO: org.apache.tajo.pullserver.TajoPullServerService
(messageReceived(400)) - PullServer baseDir:
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output>
2014-05-23 21:32:59,778 INFO: org.apache.tajo.pullserver.TajoPullServerService
(getFileCunks(552)) - BSTIndex is loaded from disk ((0=>2, 1=>2), (0=>3, 1=>2)
2014-05-23 21:32:59,778 INFO: org.apache.tajo.pullserver.TajoPullServerService
(getFileCunks(576)) - GET Request for
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output/3/0_0/output/output>
(start=(0=>2, 1=>2), end=(0=>3, 1=>2), last=true)
2014-05-23 21:32:59,779 INFO: org.apache.tajo.pullserver.TajoPullServerService
(getFileCunks(645)) - Retrieve File Chunk: (start=0, length=34)
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/aa06a2be-ca34-4981-882f-82ae8d9c93c9/tajo-localdir/q_1400880522585_0296/output/3/0_0/output/output>
2014-05-23 21:32:59,780 INFO: org.apache.tajo.worker.Task (waitForFetch(354)) -
ta_1400880522585_0296_000004_000000_00 All fetches are done!
2014-05-23 21:32:59,784 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(61)) -
[ta_1400880522585_0296_000004_000000_00] Total merge time: 0 msec
2014-05-23 21:32:59,789 INFO: BlockStateChange (logAddStoredBlock(2300)) -
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:51169 is added to
blk_1073742222_1398{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1,
replicas=[ReplicaUnderConstruction[[DISK]DS-b14668c5-a04a-461c-bc14-bf8ac25d5ac0:NORMAL|RBW]]}
size 0
2014-05-23 21:32:59,790 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(112)) - Query status of ta_1400880522585_0296_000004_000000_00 is
changed to TA_SUCCEEDED
2014-05-23 21:32:59,790 INFO: org.apache.tajo.worker.Task (run(450)) - Worker's
task counter - total:699, succeeded: 695, killed: 4, failed: 0
2014-05-23 21:32:59,791 INFO: org.apache.tajo.worker.TaskRunner (run(332)) -
Request GetTask:
eb_1400880522585_0296_000004,container_1400880522585_0296_01_001054
2014-05-23 21:32:59,791 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1069)) - [eb_1400880522585_0296_000004] Task Completion Event
(Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-05-23 21:32:59,791 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1109)) - subQuery completed - eb_1400880522585_0296_000004
(total=1, success=1, killed=0)
2014-05-23 21:32:59,791 INFO: org.apache.tajo.master.DefaultTaskScheduler
(run(103)) - TaskScheduler schedulingThread stopped
2014-05-23 21:32:59,791 INFO: org.apache.tajo.master.DefaultTaskScheduler
(stop(144)) - Task Scheduler stopped
2014-05-23 21:32:59,791 INFO: org.apache.tajo.worker.TaskRunner (run(362)) -
Received ShouldDie
flag:eb_1400880522585_0296_000004,container_1400880522585_0296_01_001054
2014-05-23 21:32:59,791 INFO: org.apache.tajo.worker.TaskRunner (stop(227)) -
Stop TaskRunner: eb_1400880522585_0296_000004
2014-05-23 21:32:59,792 INFO: org.apache.tajo.master.querymaster.Query
(handle(682)) - Processing q_1400880522585_0296 of type SUBQUERY_COMPLETED
2014-05-23 21:32:59,792 INFO: org.apache.tajo.worker.TaskRunnerManager
(stopTask(89)) - Stop
Task:eb_1400880522585_0296_000004,container_1400880522585_0296_01_001054
2014-05-23 21:32:59,792 INFO: org.apache.tajo.master.querymaster.Query
(handle(682)) - Processing q_1400880522585_0296 of type QUERY_COMPLETED
2014-05-23 21:32:59,792 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(518)) - Release Resource: 0.5,512
2014-05-23 21:32:59,792 INFO: org.apache.tajo.master.querymaster.Query
(handle(699)) - q_1400880522585_0296 Query Transitioned from QUERY_RUNNING to
QUERY_SUCCEEDED
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (handle(295)) - Query
completion notified from q_1400880522585_0296
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (handle(306)) - Query final
state: QUERY_SUCCEEDED
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (stop(187)) - Stopping
QueryMasterTask:q_1400880522585_0296
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryJobManager (stopQuery(197)) - Stop
QueryInProgress:q_1400880522585_0296
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(116)) -
=========================================================
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(117)) - Stop
query:q_1400880522585_0296
2014-05-23 21:32:59,793 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (heartbeat(266)) - Received
QueryMaster heartbeat:q_1400880522585_0296,state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=asf001.sp2.ygridcore.net
2014-05-23 21:32:59,794 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(518)) - Release Resource: 0.0,512
2014-05-23 21:32:59,794 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager (stopQueryMaster(541)) -
Released QueryMaster (q_1400880522585_0296) resource:null
2014-05-23 21:32:59,794 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(125)) -
q_1400880522585_0296 QueryMaster stopped
2014-05-23 21:32:59,795 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1400880522585_0296
2014-05-23 21:32:59,795 WARN: org.apache.tajo.master.TajoAsyncDispatcher
(stop(115)) - Interrupted Exception while stopping
2014-05-23 21:32:59,795 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:q_1400880522585_0296
2014-05-23 21:32:59,796 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (stop(215)) - Stopped
QueryMasterTask:q_1400880522585_0296
2014-05-23 21:33:00,110 INFO: org.apache.tajo.worker.TajoWorkerClientService
(closeQuery(222)) - Stop Query:q_1400880522585_0296
2014-05-23 21:33:00,111 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 98289ee9-605c-42e1-9cbe-bbb71b79abdd is removed.
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.18 sec
Running org.apache.tajo.cluster.TestServerName
Tests run: 11, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec
Running org.apache.tajo.util.TestJSPUtil
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec
Running org.apache.tajo.util.metrics.TestSystemMetrics
2014-05-23 21:33:00,177 INFO: org.apache.tajo.util.metrics.TajoSystemMetrics
(setMetricsReporter(180)) - Started metrics reporter
org.apache.tajo.util.metrics.reporter.MetricsFileScheduledReporter for
test-file-group
2014-05-23 21:33:00,177 WARN: org.apache.tajo.util.metrics.TajoSystemMetrics
(setMetricsReporter(132)) - No property test-file-group-jvm.reporters in
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/599fa1c5-ec32-46f7-85f3-c94294057c40/1400880780136.properties>
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec
Running org.apache.tajo.util.metrics.TestMetricsFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec
2014-05-23 21:33:00,197 INFO: org.apache.tajo.worker.TajoWorker (run(492)) -
============================================
2014-05-23 21:33:00,198 INFO: org.apache.tajo.worker.TajoWorker (run(493)) -
TajoWorker received SIGINT Signal
2014-05-23 21:33:00,198 INFO: org.apache.tajo.worker.TajoWorker (run(494)) -
============================================
2014-05-23 21:33:00,202 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 84ff7612-6bbd-4fa7-a91f-b70f0e9a5604 is removed.
2014-05-23 21:33:00,202 ERROR: org.apache.tajo.rpc.RpcProtos
(exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-05-23 21:33:00,203 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 5d4375de-f56d-4741-b59c-3519508f1c59 is removed.
2014-05-23 21:33:00,202 ERROR: org.apache.tajo.rpc.RpcProtos
(exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-05-23 21:33:00,202 ERROR: org.apache.tajo.rpc.RpcProtos
(exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-05-23 21:33:00,203 ERROR: org.apache.tajo.client.TajoClient (close(140)) -
java.io.IOException: Connect error to localhost/127.0.0.1:25207 cause
java.util.concurrent.RejectedExecutionException: Worker has already been
shutdown
2014-05-23 21:33:00,202 ERROR: org.apache.tajo.rpc.RpcProtos
(exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-05-23 21:33:00,205 ERROR: org.apache.tajo.client.TajoClient (close(140)) -
java.io.IOException: Connect error to localhost/127.0.0.1:25207 cause
java.util.concurrent.RejectedExecutionException: Worker has already been
shutdown
2014-05-23 21:33:00,204 ERROR: org.apache.tajo.client.TajoClient (close(140)) -
java.io.IOException: Connect error to localhost/127.0.0.1:25207 cause
java.util.concurrent.RejectedExecutionException: Worker has already been
shutdown
2014-05-23 21:33:00,207 INFO: org.apache.tajo.worker.WorkerHeartbeatService
(run(260)) - Worker Resource Heartbeat Thread stopped.
2014-05-23 21:33:00,206 ERROR: org.apache.tajo.client.TajoClient (close(140)) -
java.io.IOException: Connect error to localhost/127.0.0.1:25207 cause
java.util.concurrent.RejectedExecutionException: Worker has already been
shutdown
2014-05-23 21:33:00,228 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:25211)
shutdown
2014-05-23 21:33:00,229 INFO: org.apache.tajo.worker.TajoWorkerManagerService
(stop(95)) - TajoWorkerManagerService stopped
2014-05-23 21:33:00,231 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:25210)
shutdown
2014-05-23 21:33:00,232 INFO:
org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) -
QueryMasterManagerService stopped
2014-05-23 21:33:00,232 INFO: org.apache.tajo.master.querymaster.QueryMaster
(run(434)) - QueryMaster heartbeat thread stopped
2014-05-23 21:33:00,236 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:querymaster_1400880523027
2014-05-23 21:33:00,236 INFO: org.apache.tajo.master.querymaster.QueryMaster
(stop(160)) - QueryMaster stop
2014-05-23 21:33:00,236 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(109)) - TajoWorkerClientService stopping
2014-05-23 21:33:00,237 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on
0:0:0:0:0:0:0:0:25209) shutdown
2014-05-23 21:33:00,237 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(113)) - TajoWorkerClientService stopped
2014-05-23 21:33:00,238 INFO: org.apache.tajo.worker.TajoWorker (stop(334)) -
TajoWorker main thread exiting
Results :
Failed tests:
testCastFromTable(org.apache.tajo.engine.eval.TestSQLExpression): select
col1::timestamp as t1, col2::float from table1 where t1 = '1980-04-01
01:50:01'::timestamp expected:<1980-0[3-31 16]:50:01> but was:<1980-0[4-01
01]:50:01>
Tests run: 747, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [26.537s]
[INFO] Tajo Project POM .................................. SUCCESS [0.506s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [3.320s]
[INFO] Tajo Common ....................................... SUCCESS [52.596s]
[INFO] Tajo Algebra ...................................... SUCCESS [1.107s]
[INFO] Tajo Catalog Common ............................... SUCCESS [5.205s]
[INFO] Tajo Rpc .......................................... SUCCESS [21.296s]
[INFO] Tajo Catalog Client ............................... SUCCESS [1.012s]
[INFO] Tajo Catalog Server ............................... SUCCESS [6.169s]
[INFO] Tajo Storage ...................................... SUCCESS [49.786s]
[INFO] Tajo Core PullServer .............................. SUCCESS [0.833s]
[INFO] Tajo Client ....................................... SUCCESS [3.432s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [0.978s]
[INFO] Tajo Core ......................................... FAILURE [5:59.489s]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 8:53.268s
[INFO] Finished at: Fri May 23 21:34:01 UTC 2014
[INFO] Final Memory: 46M/431M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal
org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on
project tajo-core: There are test failures.
[ERROR]
[ERROR] Please refer to
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/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
Build step 'Execute shell' marked build as failure
