See <https://builds.apache.org/job/Tajo-master-CODEGEN-build/10/changes>
Changes:
[jhkim] TAJO-1047: DefaultTaskScheduler:allocateRackTask is failed occasionally
on JDK 1.7. (jinho)
------------------------------------------
[...truncated 311461 lines...]
[Incoming]
[q_1411200217568_0714] 1 => 2 (type=HASH_SHUFFLE, key=, num=1)
GROUP_BY(2)()
=> exprs: (avg(?avg (PROTOBUF)))
=> target list: total_avg (FLOAT8)
=> out schema:{(1) total_avg (FLOAT8)}
=> in schema:{(1) ?avg (PROTOBUF)}
SCAN(6) on eb_1411200217568_0714_000001
=> out schema: {(1) ?avg (PROTOBUF)}
=> in schema: {(1) ?avg (PROTOBUF)}
=======================================================
Block Id: eb_1411200217568_0714_000003 [TERMINAL]
=======================================================
2014-09-20 08:14:34,387 INFO: org.apache.tajo.master.querymaster.Query
(<init>(227)) -
=======================================================
The order of execution:
1: eb_1411200217568_0714_000001
2: eb_1411200217568_0714_000002
3: eb_1411200217568_0714_000003
=======================================================
2014-09-20 08:14:34,387 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(start(101)) - AsyncDispatcher started:q_1411200217568_0714
2014-09-20 08:14:34,387 INFO: org.apache.tajo.master.querymaster.Query
(handle(851)) - Processing q_1411200217568_0714 of type START
2014-09-20 08:14:34,388 INFO: org.apache.tajo.master.querymaster.Query
(handle(869)) - q_1411200217568_0714 Query Transitioned from QUERY_NEW to
QUERY_RUNNING
2014-09-20 08:14:34,388 INFO: org.apache.tajo.master.querymaster.SubQuery
(initTaskScheduler(708)) - org.apache.tajo.master.DefaultTaskScheduler is
chosen for the task scheduling for eb_1411200217568_0714_000001
2014-09-20 08:14:34,391 INFO: org.apache.tajo.storage.AbstractStorageManager
(listStatus(385)) - Total input paths to process : 1
2014-09-20 08:14:34,392 INFO: org.apache.tajo.storage.AbstractStorageManager
(getSplits(614)) - Total # of splits: 1
2014-09-20 08:14:34,392 INFO: org.apache.tajo.master.querymaster.SubQuery
(run(668)) - 1 objects are scheduled
2014-09-20 08:14:34,392 INFO: org.apache.tajo.master.DefaultTaskScheduler
(start(89)) - Start TaskScheduler
2014-09-20 08:14:34,393 INFO: org.apache.tajo.worker.TajoResourceAllocator
(calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number
of Tasks=1, Number of Cluster Slots=1
2014-09-20 08:14:34,393 INFO: org.apache.tajo.master.querymaster.SubQuery
(allocateContainers(929)) - Request Container for eb_1411200217568_0714_000001
containers=1
2014-09-20 08:14:34,393 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(252)) - Start TajoWorkerAllocationThread
2014-09-20 08:14:34,394 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(389)) - Stop TajoWorkerAllocationThread
2014-09-20 08:14:34,395 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1037)) - SubQuery (eb_1411200217568_0714_000001) has 1 containers!
2014-09-20 08:14:34,396 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(165)) - ======================== Processing
eb_1411200217568_0714_000001 of type START
2014-09-20 08:14:34,397 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(121)) - Tajo Root Dir: hdfs://localhost:60475/tajo
2014-09-20 08:14:34,397 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(122)) - Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir>
2014-09-20 08:14:34,397 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(125)) - QueryMaster Address:asf907.gq1.ygridcore.net/67.195.81.151:33706
2014-09-20 08:14:34,400 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(181)) - Start
TaskRunner:eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,401 INFO: org.apache.tajo.worker.TaskRunner (init(120)) -
TaskRunner basedir is created
(<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/output/1)>
2014-09-20 08:14:34,401 INFO: org.apache.tajo.worker.TaskRunner (run(179)) -
TaskRunner startup
2014-09-20 08:14:34,401 INFO: org.apache.tajo.worker.TaskRunner (run(196)) -
Request GetTask:
eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,405 INFO: org.apache.tajo.master.DefaultTaskScheduler
(allocateRackTask(734)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%,
Rack host: asf907.gq1.ygridcore.net
2014-09-20 08:14:34,406 INFO: org.apache.tajo.worker.TaskRunner (run(235)) -
Accumulated Received Task: 1
2014-09-20 08:14:34,406 INFO: org.apache.tajo.worker.TaskRunner (run(244)) -
Initializing: ta_1411200217568_0714_000001_000000_00
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000001_000000_00 is
changed to TA_PENDING
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.Task (<init>(194)) -
==================================
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.Task (<init>(195)) - *
Subquery ta_1411200217568_0714_000001_000000_00 is initialized
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.Task (<init>(196)) - *
InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches
(total:0) :
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.Task (<init>(206)) - *
Local task dir:
<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/output/1/0_0>
2014-09-20 08:14:34,408 INFO: org.apache.tajo.worker.Task (<init>(211)) -
==================================
2014-09-20 08:14:34,409 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000001_000000_00 is
changed to TA_RUNNING
2014-09-20 08:14:34,409 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(createInMemoryHashAggregation(958)) - The planner chooses [Hash Aggregation]
2014-09-20 08:14:34,428 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (getAppender(99)) - Create
Hash shuffle file(partId=0):
<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/output/1/hash-shuffle/0/0>
2014-09-20 08:14:34,429 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000001_000000_00 is
changed to TA_SUCCEEDED
2014-09-20 08:14:34,429 INFO: org.apache.tajo.worker.Task (run(489)) -
ta_1411200217568_0714_000001_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2014-09-20 08:14:34,429 INFO: org.apache.tajo.worker.TaskRunner (run(196)) -
Request GetTask:
eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,430 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1101)) - [eb_1411200217568_0714_000001] Task Completion Event
(Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-09-20 08:14:34,430 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1203)) - subQuery completed - eb_1411200217568_0714_000001
(total=1, success=1, killed=0)
2014-09-20 08:14:34,430 INFO: org.apache.tajo.master.DefaultTaskScheduler
(run(107)) - TaskScheduler schedulingThread stopped
2014-09-20 08:14:34,430 INFO: org.apache.tajo.master.DefaultTaskScheduler
(stop(148)) - Task Scheduler stopped
2014-09-20 08:14:34,430 INFO: org.apache.tajo.worker.TaskRunner (run(229)) -
Received ShouldDie
flag:eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,430 INFO: org.apache.tajo.master.querymaster.QueryMaster
(cleanupExecutionBlock(186)) - cleanup executionBlocks:
2014-09-20 08:14:34,430 INFO: org.apache.tajo.worker.TaskRunner (stop(150)) -
Stop TaskRunner:
eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,431 INFO: org.apache.tajo.worker.TaskRunnerManager
(stopTaskRunner(116)) - Stop
Task:eb_1411200217568_0714_000001,container_1411200217568_0714_01_002781
2014-09-20 08:14:34,432 INFO: org.apache.tajo.master.querymaster.Query
(handle(851)) - Processing q_1411200217568_0714 of type SUBQUERY_COMPLETED
2014-09-20 08:14:34,432 INFO: org.apache.tajo.master.querymaster.SubQuery
(waitingIntermediateReport(1151)) - eb_1411200217568_0714_000001, waiting
IntermediateReport: expectedTaskNum=0
2014-09-20 08:14:34,432 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(514)) - Release Resource: 0.5,512
2014-09-20 08:14:34,432 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(165)) - ======================== Processing
eb_1411200217568_0714_000001 of type STOP
2014-09-20 08:14:34,433 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(152)) - Close
HashShuffleAppender:eb_1411200217568_0714_000001, intermediates=1
2014-09-20 08:14:34,433 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close
HashShuffleAppender:eb_1411200217568_0714_000001, not a hash shuffle
2014-09-20 08:14:34,433 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(201)) - Stopped execution block:eb_1411200217568_0714_000001
2014-09-20 08:14:34,433 INFO: org.apache.tajo.master.querymaster.SubQuery
(receiveExecutionBlockReport(1175)) - eb_1411200217568_0714_000001,
receiveExecutionBlockReport:1
2014-09-20 08:14:34,434 INFO: org.apache.tajo.master.querymaster.SubQuery
(waitingIntermediateReport(1156)) - eb_1411200217568_0714_000001, completed
waiting IntermediateReport
2014-09-20 08:14:34,434 INFO: org.apache.tajo.master.querymaster.Query
(executeNextBlock(771)) - Scheduling SubQuery:eb_1411200217568_0714_000002
2014-09-20 08:14:34,434 INFO: org.apache.tajo.master.querymaster.SubQuery
(initTaskScheduler(708)) - org.apache.tajo.master.DefaultTaskScheduler is
chosen for the task scheduling for eb_1411200217568_0714_000002
2014-09-20 08:14:34,434 INFO: org.apache.tajo.master.querymaster.SubQuery
(getNonLeafTaskNum(878)) - eb_1411200217568_0714_000002, Table's volume is
approximately 1 MB
2014-09-20 08:14:34,434 INFO: org.apache.tajo.master.querymaster.SubQuery
(getNonLeafTaskNum(881)) - eb_1411200217568_0714_000002, The determined number
of non-leaf tasks is 1
2014-09-20 08:14:34,435 INFO: org.apache.tajo.master.querymaster.Repartitioner
(scheduleHashShuffledFetches(813)) - eb_1411200217568_0714_000002,
ScheduleHashShuffledFetches - Max num=1, finalFetchURI=1
2014-09-20 08:14:34,435 INFO: org.apache.tajo.master.querymaster.Repartitioner
(scheduleHashShuffledFetches(817)) - eb_1411200217568_0714_000002, No Grouping
Column - determinedTaskNum is set to 1
2014-09-20 08:14:34,435 INFO: org.apache.tajo.master.querymaster.Repartitioner
(scheduleHashShuffledFetches(833)) - eb_1411200217568_0714_000002,
DeterminedTaskNum : 1
2014-09-20 08:14:34,435 INFO: org.apache.tajo.master.querymaster.SubQuery
(run(668)) - 1 objects are scheduled
2014-09-20 08:14:34,435 INFO: org.apache.tajo.master.DefaultTaskScheduler
(start(89)) - Start TaskScheduler
2014-09-20 08:14:34,436 INFO: org.apache.tajo.worker.TajoResourceAllocator
(calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number
of Tasks=1, Number of Cluster Slots=1
2014-09-20 08:14:34,436 INFO: org.apache.tajo.master.querymaster.SubQuery
(allocateContainers(929)) - Request Container for eb_1411200217568_0714_000002
containers=1
2014-09-20 08:14:34,437 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(252)) - Start TajoWorkerAllocationThread
2014-09-20 08:14:34,437 INFO: org.apache.tajo.worker.TajoResourceAllocator
(run(389)) - Stop TajoWorkerAllocationThread
2014-09-20 08:14:34,438 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1037)) - SubQuery (eb_1411200217568_0714_000002) has 1 containers!
2014-09-20 08:14:34,439 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(165)) - ======================== Processing
eb_1411200217568_0714_000002 of type START
2014-09-20 08:14:34,439 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(121)) - Tajo Root Dir: hdfs://localhost:60475/tajo
2014-09-20 08:14:34,439 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(122)) - Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir>
2014-09-20 08:14:34,439 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(125)) - QueryMaster Address:asf907.gq1.ygridcore.net/67.195.81.151:33706
2014-09-20 08:14:34,442 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(181)) - Start
TaskRunner:eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,442 INFO: org.apache.tajo.worker.TaskRunner (init(120)) -
TaskRunner basedir is created
(<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/output/2)>
2014-09-20 08:14:34,442 INFO: org.apache.tajo.worker.TaskRunner (run(179)) -
TaskRunner startup
2014-09-20 08:14:34,443 INFO: org.apache.tajo.worker.TaskRunner (run(196)) -
Request GetTask:
eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,444 INFO: org.apache.tajo.worker.TaskRunner (run(235)) -
Accumulated Received Task: 1
2014-09-20 08:14:34,444 INFO: org.apache.tajo.worker.TaskRunner (run(244)) -
Initializing: ta_1411200217568_0714_000002_000000_00
2014-09-20 08:14:34,445 INFO: org.apache.tajo.worker.Task (<init>(189)) -
Output File Path:
hdfs://localhost:60475/tmp/tajo-jenkins/staging/q_1411200217568_0714/RESULT/part-02-000000-000
2014-09-20 08:14:34,445 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000002_000000_00 is
changed to TA_PENDING
2014-09-20 08:14:34,445 INFO: org.apache.tajo.worker.Task (<init>(194)) -
==================================
2014-09-20 08:14:34,446 INFO: org.apache.tajo.worker.Task (<init>(195)) - *
Subquery ta_1411200217568_0714_000002_000000_00 is initialized
2014-09-20 08:14:34,446 INFO: org.apache.tajo.worker.Task (<init>(196)) - *
InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2014-09-20 08:14:34,446 INFO: org.apache.tajo.worker.Task (<init>(206)) - *
Local task dir:
<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/output/2/0_0>
2014-09-20 08:14:34,446 INFO: org.apache.tajo.worker.Task (<init>(211)) -
==================================
2014-09-20 08:14:34,447 INFO: org.apache.tajo.worker.Task (init(229)) - the
directory is created
<https://builds.apache.org/job/Tajo-master-CODEGEN-build/ws/tajo-core/target/test-data/174e8513-ca51-4b6a-bfe8-07a886148bd5/tajo-localdir/q_1411200217568_0714/in/eb_1411200217568_0714_000002/0/0/eb_1411200217568_0714_000001>
2014-09-20 08:14:34,452 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000002_000000_00 is
changed to TA_RUNNING
2014-09-20 08:14:34,452 INFO: org.apache.tajo.pullserver.TajoPullServerService
(channelOpen(473)) - Current number of shuffle connections (2)
2014-09-20 08:14:34,453 INFO: org.apache.tajo.worker.Fetcher (get(139)) -
Status: FETCH_FETCHING,
URI:http://asf907.gq1.ygridcore.net:48432/?qid=q_1411200217568_0714&sid=1&p=0&type=h
2014-09-20 08:14:34,453 INFO: org.apache.tajo.pullserver.TajoPullServerService
(messageReceived(587)) - RequestURL:
/?qid=q_1411200217568_0714&sid=1&p=0&type=h, fileLen=12
2014-09-20 08:14:34,454 INFO: org.apache.tajo.pullserver.TajoPullServerService
(decrementRemainFiles(427)) - PullServer processing status: totalTime=1 ms,
makeFileListTime=0 ms, minTime=0 ms, maxTime=0 ms, numFiles=1, numSlowFile=0
2014-09-20 08:14:34,454 INFO: org.apache.tajo.worker.Fetcher (get(156)) -
Fetcher finished:2 ms, FETCH_FINISHED,
URI:http://asf907.gq1.ygridcore.net:48432/?qid=q_1411200217568_0714&sid=1&p=0&type=h
2014-09-20 08:14:34,454 INFO: org.apache.tajo.worker.Task (waitForFetch(394)) -
ta_1411200217568_0714_000002_000000_00 All fetches are done!
2014-09-20 08:14:34,455 INFO:
org.apache.tajo.engine.planner.PhysicalPlannerImpl
(createInMemoryHashAggregation(958)) - The planner chooses [Hash Aggregation]
2014-09-20 08:14:34,479 INFO: BlockStateChange (logAddStoredBlock(2300)) -
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58647 is added to
blk_1073743130_2306{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1,
replicas=[ReplicaUnderConstruction[[DISK]DS-28efbd39-5f2d-4f79-bd61-2bc95e66faf4:NORMAL|RBW]]}
size 0
2014-09-20 08:14:34,480 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(147)) - Query status of ta_1411200217568_0714_000002_000000_00 is
changed to TA_SUCCEEDED
2014-09-20 08:14:34,480 INFO: org.apache.tajo.worker.Task (run(489)) -
ta_1411200217568_0714_000002_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2014-09-20 08:14:34,481 INFO: org.apache.tajo.worker.TaskRunner (run(196)) -
Request GetTask:
eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,481 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1101)) - [eb_1411200217568_0714_000002] Task Completion Event
(Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-09-20 08:14:34,481 INFO: org.apache.tajo.master.querymaster.SubQuery
(transition(1203)) - subQuery completed - eb_1411200217568_0714_000002
(total=1, success=1, killed=0)
2014-09-20 08:14:34,481 INFO: org.apache.tajo.master.DefaultTaskScheduler
(run(107)) - TaskScheduler schedulingThread stopped
2014-09-20 08:14:34,481 INFO: org.apache.tajo.master.DefaultTaskScheduler
(stop(148)) - Task Scheduler stopped
2014-09-20 08:14:34,482 INFO: org.apache.tajo.worker.TaskRunner (run(229)) -
Received ShouldDie
flag:eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,482 INFO: org.apache.tajo.master.querymaster.QueryMaster
(cleanupExecutionBlock(186)) - cleanup executionBlocks:
eb_1411200217568_0714_000001
2014-09-20 08:14:34,482 INFO: org.apache.tajo.worker.TaskRunner (stop(150)) -
Stop TaskRunner:
eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,482 INFO: org.apache.tajo.worker.TaskRunnerManager
(stopTaskRunner(116)) - Stop
Task:eb_1411200217568_0714_000002,container_1411200217568_0714_01_002782
2014-09-20 08:14:34,483 INFO: org.apache.tajo.master.querymaster.Query
(handle(851)) - Processing q_1411200217568_0714 of type SUBQUERY_COMPLETED
2014-09-20 08:14:34,483 INFO: org.apache.tajo.master.querymaster.Query
(handle(851)) - Processing q_1411200217568_0714 of type QUERY_COMPLETED
2014-09-20 08:14:34,483 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(514)) - Release Resource: 0.5,512
2014-09-20 08:14:34,483 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(165)) - ======================== Processing
eb_1411200217568_0714_000002 of type STOP
2014-09-20 08:14:34,484 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close
HashShuffleAppender:eb_1411200217568_0714_000002, not a hash shuffle
2014-09-20 08:14:34,484 INFO: org.apache.tajo.master.querymaster.SubQuery
(receiveExecutionBlockReport(1175)) - eb_1411200217568_0714_000002,
receiveExecutionBlockReport:1
2014-09-20 08:14:34,484 INFO: org.apache.tajo.master.querymaster.Query
(handle(869)) - q_1411200217568_0714 Query Transitioned from QUERY_RUNNING to
QUERY_SUCCEEDED
2014-09-20 08:14:34,484 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (handle(323)) - Query
completion notified from q_1411200217568_0714
2014-09-20 08:14:34,484 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (handle(334)) - Query final
state: QUERY_SUCCEEDED
2014-09-20 08:14:34,485 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (stop(188)) - Stopping
QueryMasterTask:q_1411200217568_0714
2014-09-20 08:14:34,485 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (heartbeat(265)) - Received
QueryMaster heartbeat:q_1411200217568_0714,state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=asf907.gq1.ygridcore.net
2014-09-20 08:14:34,485 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(116)) -
=========================================================
2014-09-20 08:14:34,485 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(117)) - Stop
query:q_1411200217568_0714
2014-09-20 08:14:34,485 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager
(releaseWorkerResource(514)) - Release Resource: 0.0,512
2014-09-20 08:14:34,486 INFO:
org.apache.tajo.master.rm.TajoWorkerResourceManager (stopQueryMaster(536)) -
Released QueryMaster (q_1411200217568_0714) resource.
2014-09-20 08:14:34,486 INFO:
org.apache.tajo.master.querymaster.QueryInProgress (stop(125)) -
q_1411200217568_0714 QueryMaster stopped
2014-09-20 08:14:34,486 WARN: org.apache.tajo.master.TajoAsyncDispatcher
(stop(115)) - Interrupted Exception while stopping
2014-09-20 08:14:34,486 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1411200217568_0714
2014-09-20 08:14:34,486 INFO:
org.apache.tajo.master.querymaster.QueryJobManager (stopQuery(204)) - Stop
QueryInProgress:q_1411200217568_0714
2014-09-20 08:14:34,487 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close
HashShuffleAppender:eb_1411200217568_0714_000002, not a hash shuffle
2014-09-20 08:14:34,487 INFO: org.apache.tajo.worker.TaskRunnerManager
(handle(201)) - Stopped execution block:eb_1411200217568_0714_000002
2014-09-20 08:14:34,487 WARN: org.apache.tajo.master.TajoAsyncDispatcher
(stop(115)) - Interrupted Exception while stopping
2014-09-20 08:14:34,487 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:q_1411200217568_0714
2014-09-20 08:14:34,487 INFO:
org.apache.tajo.master.querymaster.QueryMasterTask (stop(243)) - Stopped
QueryMasterTask:q_1411200217568_0714
2014-09-20 08:14:34,488 INFO: org.apache.tajo.master.querymaster.QueryMaster
(cleanup(210)) - cleanup query resources : q_1411200217568_0714
2014-09-20 08:14:34,723 INFO: org.apache.tajo.worker.TajoWorkerClientService
(closeQuery(229)) - Stop Query:q_1411200217568_0714
2014-09-20 08:14:34,724 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session eaad775a-d8e5-4fff-8fb4-242b0fd00fb9 is removed.
Tests run: 11, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 6.196 sec - in
org.apache.tajo.engine.function.TestBuiltinFunctions
Running org.apache.tajo.cluster.TestWorkerConnectionInfo
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in
org.apache.tajo.cluster.TestWorkerConnectionInfo
Running org.apache.tajo.cluster.TestServerName
Tests run: 11, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.003 sec - in
org.apache.tajo.cluster.TestServerName
Running org.apache.tajo.TestTajoIds
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 sec - in
org.apache.tajo.TestTajoIds
2014-09-20 08:14:34,738 INFO: org.apache.tajo.worker.TajoWorker (run(578)) -
============================================
2014-09-20 08:14:34,738 INFO: org.apache.tajo.worker.TajoWorker (run(579)) -
TajoWorker received SIGINT Signal
2014-09-20 08:14:34,738 INFO: org.apache.tajo.worker.TajoWorker (run(580)) -
============================================
2014-09-20 08:14:34,743 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 917e8981-fe1d-49f8-af5f-2992893e5693 is removed.
2014-09-20 08:14:34,744 INFO: org.apache.tajo.worker.TajoWorker (run(578)) -
============================================
2014-09-20 08:14:34,749 INFO: org.apache.tajo.worker.TajoWorker (run(579)) -
TajoWorker received SIGINT Signal
2014-09-20 08:14:34,749 INFO: org.apache.tajo.worker.TajoWorker (run(580)) -
============================================
2014-09-20 08:14:34,756 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session faaae7c5-2f23-4458-a9af-08a002f63380 is removed.
2014-09-20 08:14:34,757 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session a3af7327-50a4-421f-9d82-53f03df8377d is removed.
2014-09-20 08:14:34,757 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 2f2897cf-0b4e-4a97-9d97-2b1f05bbcfbe is removed.
2014-09-20 08:14:34,759 INFO: org.apache.tajo.master.session.SessionManager
(removeSession(80)) - Session 0056c1e7-114a-48bf-a585-1446d6813cbd is removed.
2014-09-20 08:14:34,816 INFO: org.apache.tajo.worker.WorkerHeartbeatService
(run(242)) - Worker Resource Heartbeat Thread stopped.
2014-09-20 08:14:34,816 INFO: org.apache.tajo.worker.WorkerHeartbeatService
(run(242)) - Worker Resource Heartbeat Thread stopped.
2014-09-20 08:14:34,831 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:33706)
shutdown
2014-09-20 08:14:34,832 INFO:
org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) -
QueryMasterManagerService stopped
2014-09-20 08:14:34,832 INFO: org.apache.tajo.master.querymaster.QueryMaster
(run(553)) - QueryMaster heartbeat thread stopped
2014-09-20 08:14:34,832 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:querymaster_1411200218346
2014-09-20 08:14:34,833 INFO: org.apache.tajo.master.querymaster.QueryMaster
(stop(173)) - QueryMaster stop
2014-09-20 08:14:34,833 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(108)) - TajoWorkerClientService stopping
2014-09-20 08:14:34,835 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:33715)
shutdown
2014-09-20 08:14:34,835 INFO:
org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) -
QueryMasterManagerService stopped
2014-09-20 08:14:34,836 INFO: org.apache.tajo.master.querymaster.QueryMaster
(run(553)) - QueryMaster heartbeat thread stopped
2014-09-20 08:14:34,837 INFO: org.apache.tajo.master.TajoAsyncDispatcher
(stop(122)) - AsyncDispatcher stopped:querymaster_1411200241594
2014-09-20 08:14:34,837 INFO: org.apache.tajo.master.querymaster.QueryMaster
(stop(173)) - QueryMaster stop
2014-09-20 08:14:34,837 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(108)) - TajoWorkerClientService stopping
2014-09-20 08:14:34,838 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on
0:0:0:0:0:0:0:0:33705) shutdown
2014-09-20 08:14:34,838 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(112)) - TajoWorkerClientService stopped
2014-09-20 08:14:34,841 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on
0:0:0:0:0:0:0:0:33714) shutdown
2014-09-20 08:14:34,841 INFO: org.apache.tajo.worker.TajoWorkerClientService
(stop(112)) - TajoWorkerClientService stopped
2014-09-20 08:14:34,845 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:33704)
shutdown
2014-09-20 08:14:34,845 INFO: org.apache.tajo.worker.TajoWorkerManagerService
(stop(97)) - TajoWorkerManagerService stopped
2014-09-20 08:14:34,845 INFO: org.apache.tajo.worker.TajoWorker
(serviceStop(376)) - TajoWorker main thread exiting
2014-09-20 08:14:34,850 INFO: org.apache.tajo.rpc.NettyServerBase
(shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:33713)
shutdown
2014-09-20 08:14:34,851 INFO: org.apache.tajo.worker.TajoWorkerManagerService
(stop(97)) - TajoWorkerManagerService stopped
2014-09-20 08:14:34,854 INFO: org.apache.tajo.worker.TajoWorker
(serviceStop(376)) - TajoWorker main thread exiting
Results :
Tests in error:
TestPhysicalPlanner.testPartitionedStorePlanWithEmptyGroupingSet:795 ? IO
java...
Tests run: 1168, Failures: 0, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.608 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.180 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.191 s]
[INFO] Tajo Common ....................................... SUCCESS [ 38.799 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 1.415 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.253 s]
[INFO] Tajo Rpc .......................................... SUCCESS [ 25.675 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.017 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 5.554 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 43.322 s]
[INFO] Tajo Core PullServer .............................. SUCCESS [ 0.759 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.913 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.457 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 0.639 s]
[INFO] Tajo Core ......................................... FAILURE [11:22 min]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 13:35 min
[INFO] Finished at: 2014-09-20T08:14:35+00:00
[INFO] Final Memory: 78M/1172M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal
org.apache.maven.plugins:maven-surefire-plugin:2.16:test (default-test) on
project tajo-core: There are test failures.
[ERROR]
[ERROR] Please refer to
<https://builds.apache.org/job/Tajo-master-CODEGEN-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
Updating TAJO-1047
