See <https://builds.apache.org/job/Tajo-master-nightly/634/changes>
Changes: [jihoonson] TAJO-1366: The timestamp type conversion occasionally leads to wrong results. (jihoon) [jihun] TAJO-1362: Resolve findbug warnings on Tajo Core Module [jihun] TAJO-527: Upgrade to Netty 4 ------------------------------------------ [...truncated 190826 lines...] 2015-03-04 02:12:10,313 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000001,container_1425434618483_0477_01_001680 2015-03-04 02:12:10,314 INFO: org.apache.tajo.querymaster.Stage (transition(1346)) - Stage finalize - eb_1425434618483_0477_000001 (total=2, success=2, killed=0) 2015-03-04 02:12:10,314 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-03-04 02:12:10,314 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(109)) - TaskScheduler schedulingThread stopped 2015-03-04 02:12:10,314 INFO: org.apache.tajo.worker.TaskRunner (run(256)) - Received ShouldDie flag:eb_1425434618483_0477_000001,container_1425434618483_0477_01_001680 2015-03-04 02:12:10,314 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(183)) - cleanup executionBlocks: 2015-03-04 02:12:10,314 INFO: org.apache.tajo.worker.TaskRunner (stop(152)) - Stop TaskRunner: eb_1425434618483_0477_000001,container_1425434618483_0477_01_001680 2015-03-04 02:12:10,315 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTaskRunner(109)) - Stop Task:eb_1425434618483_0477_000001,container_1425434618483_0477_01_001680 2015-03-04 02:12:10,315 INFO: org.apache.tajo.querymaster.Stage (transition(1352)) - eb_1425434618483_0477_000001, waiting for shuffle reports. expected Tasks:2 2015-03-04 02:12:10,315 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(158)) - ======================== Processing eb_1425434618483_0477_000001 of type STOP 2015-03-04 02:12:10,315 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.5,512 2015-03-04 02:12:10,316 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1425434618483_0477_000001, not a hash shuffle 2015-03-04 02:12:10,316 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1425434618483_0477_000001, not a hash shuffle 2015-03-04 02:12:10,316 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(198)) - Stopped execution block:eb_1425434618483_0477_000001 2015-03-04 02:12:10,316 INFO: org.apache.tajo.querymaster.Stage (transition(1332)) - eb_1425434618483_0477_000001, Finalized shuffle reports: 2 2015-03-04 02:12:10,316 INFO: org.apache.tajo.querymaster.Stage (transition(1396)) - Stage completed - eb_1425434618483_0477_000001 (total=2, success=2, killed=0) 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type STAGE_COMPLETED 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(890)) - eb_1425434618483_0477_000002, Outer volume: 1.0MB, Inner volume: 1.0MB 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(896)) - eb_1425434618483_0477_000002, Bigger Table's volume is approximately 1 MB 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(925)) - eb_1425434618483_0477_000002, The determined number of join partitions is 1 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(846)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1425434618483_0477_000002 2015-03-04 02:12:10,317 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(635)) - Scheduling Stage:eb_1425434618483_0477_000002 2015-03-04 02:12:10,319 INFO: org.apache.tajo.storage.FileStorageManager (listStatus(359)) - Total input paths to process : 1 2015-03-04 02:12:10,320 INFO: org.apache.tajo.storage.FileStorageManager (getSplits(589)) - Total # of splits: 1 2015-03-04 02:12:10,320 INFO: org.apache.tajo.querymaster.Stage (run(798)) - 1 objects are scheduled 2015-03-04 02:12:10,320 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(91)) - Start TaskScheduler 2015-03-04 02:12:10,320 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(102)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1 2015-03-04 02:12:10,320 INFO: org.apache.tajo.querymaster.Stage (allocateContainers(1059)) - Request Container for eb_1425434618483_0477_000002 containers=1 2015-03-04 02:12:10,321 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(262)) - Start TajoWorkerAllocationThread 2015-03-04 02:12:10,322 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(375)) - Stop TajoWorkerAllocationThread 2015-03-04 02:12:10,322 INFO: org.apache.tajo.querymaster.Stage (transition(1173)) - Stage (eb_1425434618483_0477_000002) has 1 containers! 2015-03-04 02:12:10,323 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(158)) - ======================== Processing eb_1425434618483_0477_000002 of type START 2015-03-04 02:12:10,323 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(123)) - Tajo Root Dir: hdfs://localhost:58237/tajo 2015-03-04 02:12:10,323 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(124)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir> 2015-03-04 02:12:10,324 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(127)) - QueryMaster Address:asf908.gq1.ygridcore.net/67.195.81.152:32710 2015-03-04 02:12:10,325 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(176)) - Start TaskRunner:eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,325 INFO: org.apache.tajo.worker.TaskRunner (init(126)) - TaskRunner basedir is created (<https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/2)> 2015-03-04 02:12:10,325 INFO: org.apache.tajo.worker.TaskRunner (run(187)) - TaskRunner startup 2015-03-04 02:12:10,325 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,327 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(739)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: asf908.gq1.ygridcore.net 2015-03-04 02:12:10,327 INFO: org.apache.tajo.worker.TaskRunner (run(262)) - Accumulated Received Task: 1 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.TaskRunner (run(271)) - Initializing: ta_1425434618483_0477_000002_000000_00 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000002_000000_00 is changed to TA_PENDING 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.Task (initPlan(173)) - ================================== 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.Task (initPlan(174)) - * Stage ta_1425434618483_0477_000002_000000_00 is initialized 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.Task (initPlan(175)) - * InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) : 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.Task (initPlan(185)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/2/0_0> 2015-03-04 02:12:10,328 INFO: org.apache.tajo.worker.Task (initPlan(190)) - ================================== 2015-03-04 02:12:10,329 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000002_000000_00 is changed to TA_RUNNING 2015-03-04 02:12:10,333 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (getAppender(99)) - Create Hash shuffle file(partId=0): <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/2/hash-shuffle/0/0> 2015-03-04 02:12:10,334 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000002_000000_00 is changed to TA_SUCCEEDED 2015-03-04 02:12:10,334 INFO: org.apache.tajo.worker.Task (run(461)) - ta_1425434618483_0477_000002_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0 2015-03-04 02:12:10,334 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,334 INFO: org.apache.tajo.querymaster.Stage (transition(1346)) - Stage finalize - eb_1425434618483_0477_000002 (total=1, success=1, killed=0) 2015-03-04 02:12:10,335 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(109)) - TaskScheduler schedulingThread stopped 2015-03-04 02:12:10,335 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-03-04 02:12:10,335 INFO: org.apache.tajo.worker.TaskRunner (run(256)) - Received ShouldDie flag:eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,335 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(183)) - cleanup executionBlocks: 2015-03-04 02:12:10,335 INFO: org.apache.tajo.worker.TaskRunner (stop(152)) - Stop TaskRunner: eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,335 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTaskRunner(109)) - Stop Task:eb_1425434618483_0477_000002,container_1425434618483_0477_01_001681 2015-03-04 02:12:10,336 INFO: org.apache.tajo.querymaster.Stage (transition(1352)) - eb_1425434618483_0477_000002, waiting for shuffle reports. expected Tasks:1 2015-03-04 02:12:10,336 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(158)) - ======================== Processing eb_1425434618483_0477_000002 of type STOP 2015-03-04 02:12:10,336 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.5,512 2015-03-04 02:12:10,337 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(152)) - Close HashShuffleAppender:eb_1425434618483_0477_000002, intermediates=1 2015-03-04 02:12:10,337 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1425434618483_0477_000002, not a hash shuffle 2015-03-04 02:12:10,337 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(198)) - Stopped execution block:eb_1425434618483_0477_000002 2015-03-04 02:12:10,337 INFO: org.apache.tajo.querymaster.Stage (transition(1332)) - eb_1425434618483_0477_000002, Finalized shuffle reports: 1 2015-03-04 02:12:10,337 INFO: org.apache.tajo.querymaster.Stage (transition(1396)) - Stage completed - eb_1425434618483_0477_000002 (total=1, success=1, killed=0) 2015-03-04 02:12:10,338 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type STAGE_COMPLETED 2015-03-04 02:12:10,338 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(890)) - eb_1425434618483_0477_000003, Outer volume: 1.0MB, Inner volume: 1.0MB 2015-03-04 02:12:10,338 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(896)) - eb_1425434618483_0477_000003, Bigger Table's volume is approximately 1 MB 2015-03-04 02:12:10,338 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(925)) - eb_1425434618483_0477_000003, The determined number of join partitions is 1 2015-03-04 02:12:10,338 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(846)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1425434618483_0477_000003 2015-03-04 02:12:10,339 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(635)) - Scheduling Stage:eb_1425434618483_0477_000003 2015-03-04 02:12:10,339 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleFragmentsForJoinQuery(143)) - Scan (table=eb_1425434618483_0477_000001, path=/) 's input data is zero. Inner join's result is empty. 2015-03-04 02:12:10,339 INFO: org.apache.tajo.querymaster.Stage (run(798)) - 0 objects are scheduled 2015-03-04 02:12:10,339 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-03-04 02:12:10,339 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(183)) - cleanup executionBlocks: eb_1425434618483_0477_000001,eb_1425434618483_0477_000002 2015-03-04 02:12:10,340 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type STAGE_COMPLETED 2015-03-04 02:12:10,340 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(890)) - eb_1425434618483_0477_000004, Outer volume: 1.0MB, Inner volume: 1.0MB 2015-03-04 02:12:10,340 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(896)) - eb_1425434618483_0477_000004, Bigger Table's volume is approximately 1 MB 2015-03-04 02:12:10,341 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(925)) - eb_1425434618483_0477_000004, The determined number of join partitions is 1 2015-03-04 02:12:10,341 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(846)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1425434618483_0477_000004 2015-03-04 02:12:10,341 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(635)) - Scheduling Stage:eb_1425434618483_0477_000004 2015-03-04 02:12:10,342 INFO: org.apache.tajo.storage.FileStorageManager (listStatus(359)) - Total input paths to process : 3 2015-03-04 02:12:10,345 INFO: org.apache.tajo.storage.FileStorageManager (getSplits(589)) - Total # of splits: 3 2015-03-04 02:12:10,345 INFO: org.apache.tajo.querymaster.Stage (run(798)) - 3 objects are scheduled 2015-03-04 02:12:10,345 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(91)) - Start TaskScheduler 2015-03-04 02:12:10,345 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(102)) - CalculateNumberRequestContainer - Number of Tasks=3, Number of Cluster Slots=1 2015-03-04 02:12:10,345 INFO: org.apache.tajo.querymaster.Stage (allocateContainers(1059)) - Request Container for eb_1425434618483_0477_000004 containers=1 2015-03-04 02:12:10,346 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(262)) - Start TajoWorkerAllocationThread 2015-03-04 02:12:10,346 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(375)) - Stop TajoWorkerAllocationThread 2015-03-04 02:12:10,346 INFO: org.apache.tajo.querymaster.Stage (transition(1173)) - Stage (eb_1425434618483_0477_000004) has 1 containers! 2015-03-04 02:12:10,347 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(158)) - ======================== Processing eb_1425434618483_0477_000004 of type START 2015-03-04 02:12:10,347 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(123)) - Tajo Root Dir: hdfs://localhost:58237/tajo 2015-03-04 02:12:10,347 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(124)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir> 2015-03-04 02:12:10,347 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(127)) - QueryMaster Address:asf908.gq1.ygridcore.net/67.195.81.152:32710 2015-03-04 02:12:10,348 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(176)) - Start TaskRunner:eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,349 INFO: org.apache.tajo.worker.TaskRunner (init(126)) - TaskRunner basedir is created (<https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/4)> 2015-03-04 02:12:10,349 INFO: org.apache.tajo.worker.TaskRunner (run(187)) - TaskRunner startup 2015-03-04 02:12:10,349 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,350 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(739)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: asf908.gq1.ygridcore.net 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.TaskRunner (run(262)) - Accumulated Received Task: 1 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.TaskRunner (run(271)) - Initializing: ta_1425434618483_0477_000004_000000_00 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000000_00 is changed to TA_PENDING 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.Task (initPlan(173)) - ================================== 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.Task (initPlan(174)) - * Stage ta_1425434618483_0477_000004_000000_00 is initialized 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.Task (initPlan(175)) - * InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) : 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.Task (initPlan(185)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/4/0_0> 2015-03-04 02:12:10,351 INFO: org.apache.tajo.worker.Task (initPlan(190)) - ================================== 2015-03-04 02:12:10,352 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000000_00 is changed to TA_RUNNING 2015-03-04 02:12:10,356 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (getAppender(99)) - Create Hash shuffle file(partId=0): <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/4/hash-shuffle/0/0> 2015-03-04 02:12:10,356 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000000_00 is changed to TA_SUCCEEDED 2015-03-04 02:12:10,356 INFO: org.apache.tajo.worker.Task (run(461)) - ta_1425434618483_0477_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0 2015-03-04 02:12:10,356 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,356 INFO: org.apache.tajo.querymaster.Stage (transition(1250)) - [eb_1425434618483_0477_000004] Task Completion Event (Total: 3, Success: 1, Killed: 0, Failed: 0) 2015-03-04 02:12:10,357 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(739)) - Assigned Local/Rack/Total: (0/2/2), Locality: 0.00%, Rack host: asf908.gq1.ygridcore.net 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.TaskRunner (run(262)) - Accumulated Received Task: 2 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.TaskRunner (run(271)) - Initializing: ta_1425434618483_0477_000004_000001_00 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000001_00 is changed to TA_PENDING 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.Task (initPlan(173)) - ================================== 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.Task (initPlan(174)) - * Stage ta_1425434618483_0477_000004_000001_00 is initialized 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.Task (initPlan(175)) - * InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) : 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.Task (initPlan(185)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/4/1_0> 2015-03-04 02:12:10,358 INFO: org.apache.tajo.worker.Task (initPlan(190)) - ================================== 2015-03-04 02:12:10,359 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000001_00 is changed to TA_RUNNING 2015-03-04 02:12:10,361 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000001_00 is changed to TA_SUCCEEDED 2015-03-04 02:12:10,361 INFO: org.apache.tajo.worker.Task (run(461)) - ta_1425434618483_0477_000004_000001_00 completed. Worker's task counter - total:2, succeeded: 2, killed: 0, failed: 0 2015-03-04 02:12:10,361 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,362 INFO: org.apache.tajo.querymaster.Stage (transition(1250)) - [eb_1425434618483_0477_000004] Task Completion Event (Total: 3, Success: 2, Killed: 0, Failed: 0) 2015-03-04 02:12:10,362 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(739)) - Assigned Local/Rack/Total: (0/3/3), Locality: 0.00%, Rack host: asf908.gq1.ygridcore.net 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.TaskRunner (run(262)) - Accumulated Received Task: 3 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.TaskRunner (run(271)) - Initializing: ta_1425434618483_0477_000004_000002_00 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000002_00 is changed to TA_PENDING 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.Task (initPlan(173)) - ================================== 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.Task (initPlan(174)) - * Stage ta_1425434618483_0477_000004_000002_00 is initialized 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.Task (initPlan(175)) - * InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) : 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.Task (initPlan(185)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/test-data/468fd867-a0e3-4c44-a3b4-3db707e6921e/tajo-localdir/q_1425434618483_0477/output/4/2_0> 2015-03-04 02:12:10,363 INFO: org.apache.tajo.worker.Task (initPlan(190)) - ================================== 2015-03-04 02:12:10,364 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000002_00 is changed to TA_RUNNING 2015-03-04 02:12:10,366 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1425434618483_0477_000004_000002_00 is changed to TA_SUCCEEDED 2015-03-04 02:12:10,367 INFO: org.apache.tajo.worker.Task (run(461)) - ta_1425434618483_0477_000004_000002_00 completed. Worker's task counter - total:3, succeeded: 3, killed: 0, failed: 0 2015-03-04 02:12:10,367 INFO: org.apache.tajo.worker.TaskRunner (run(218)) - Request GetTask: eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,367 INFO: org.apache.tajo.querymaster.Stage (transition(1346)) - Stage finalize - eb_1425434618483_0477_000004 (total=3, success=3, killed=0) 2015-03-04 02:12:10,367 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-03-04 02:12:10,367 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(109)) - TaskScheduler schedulingThread stopped 2015-03-04 02:12:10,368 INFO: org.apache.tajo.worker.TaskRunner (run(256)) - Received ShouldDie flag:eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,368 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(183)) - cleanup executionBlocks: 2015-03-04 02:12:10,368 INFO: org.apache.tajo.worker.TaskRunner (stop(152)) - Stop TaskRunner: eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,368 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTaskRunner(109)) - Stop Task:eb_1425434618483_0477_000004,container_1425434618483_0477_01_001682 2015-03-04 02:12:10,369 INFO: org.apache.tajo.querymaster.Stage (transition(1352)) - eb_1425434618483_0477_000004, waiting for shuffle reports. expected Tasks:3 2015-03-04 02:12:10,369 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.5,512 2015-03-04 02:12:10,369 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(158)) - ======================== Processing eb_1425434618483_0477_000004 of type STOP 2015-03-04 02:12:10,370 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(152)) - Close HashShuffleAppender:eb_1425434618483_0477_000004, intermediates=1 2015-03-04 02:12:10,370 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1425434618483_0477_000004, not a hash shuffle 2015-03-04 02:12:10,370 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(198)) - Stopped execution block:eb_1425434618483_0477_000004 2015-03-04 02:12:10,370 INFO: org.apache.tajo.querymaster.Stage (transition(1332)) - eb_1425434618483_0477_000004, Finalized shuffle reports: 3 2015-03-04 02:12:10,371 INFO: org.apache.tajo.querymaster.Stage (transition(1396)) - Stage completed - eb_1425434618483_0477_000004 (total=3, success=3, killed=0) 2015-03-04 02:12:10,371 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type STAGE_COMPLETED 2015-03-04 02:12:10,371 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(846)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1425434618483_0477_000005 2015-03-04 02:12:10,371 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(635)) - Scheduling Stage:eb_1425434618483_0477_000005 2015-03-04 02:12:10,372 INFO: org.apache.tajo.querymaster.Stage (run(798)) - 0 objects are scheduled 2015-03-04 02:12:10,372 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-03-04 02:12:10,372 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(183)) - cleanup executionBlocks: eb_1425434618483_0477_000003,eb_1425434618483_0477_000004 2015-03-04 02:12:10,372 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type STAGE_COMPLETED 2015-03-04 02:12:10,373 INFO: org.apache.tajo.querymaster.Query (handle(721)) - Processing q_1425434618483_0477 of type QUERY_COMPLETED 2015-03-04 02:12:10,373 INFO: org.apache.tajo.querymaster.Query (handle(739)) - q_1425434618483_0477 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED 2015-03-04 02:12:10,373 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(279)) - Query completion notified from q_1425434618483_0477 2015-03-04 02:12:10,373 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(290)) - Query final state: QUERY_SUCCEEDED 2015-03-04 02:12:10,374 INFO: org.apache.tajo.querymaster.QueryMasterTask (stop(186)) - Stopping QueryMasterTask:q_1425434618483_0477 2015-03-04 02:12:10,374 INFO: org.apache.tajo.querymaster.QueryMasterTask (stop(199)) - Stopped QueryMasterTask:q_1425434618483_0477 2015-03-04 02:12:10,374 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(219)) - Received QueryMaster heartbeat:q_1425434618483_0477,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf908.gq1.ygridcore.net 2015-03-04 02:12:10,374 INFO: org.apache.tajo.querymaster.QueryMaster (cleanup(210)) - cleanup query resources : q_1425434618483_0477 2015-03-04 02:12:10,374 INFO: org.apache.tajo.master.QueryManager (stopQuery(252)) - Stop QueryInProgress:q_1425434618483_0477 2015-03-04 02:12:10,374 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(109)) - ========================================================= 2015-03-04 02:12:10,375 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(110)) - Stop query:q_1425434618483_0477 2015-03-04 02:12:10,375 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.0,512 2015-03-04 02:12:10,375 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseQueryMaster(535)) - Released QueryMaster (q_1425434618483_0477) resource. 2015-03-04 02:12:10,378 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(362)) - Saving query summary: hdfs://localhost:58237/tmp/tajo-jenkins/staging/history/20150304/query-detail/q_1425434618483_0477/query.hist 2015-03-04 02:12:10,384 INFO: BlockStateChange (logAddStoredBlock(2339)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40274 is added to blk_1073744557_3733{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e9ba800-2b88-46aa-abf9-f97b80843a3a:NORMAL|RBW]]} size 0 2015-03-04 02:12:10,387 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(376)) - Saving query unit: hdfs://localhost:58237/tmp/tajo-jenkins/staging/history/20150304/query-detail/q_1425434618483_0477/eb_1425434618483_0477_000004.hist 2015-03-04 02:12:10,391 INFO: BlockStateChange (logAddStoredBlock(2339)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40274 is added to blk_1073744558_3734{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-bc2b6c9f-6544-4884-b136-f5bdad3a082a:NORMAL|RBW]]} size 0 2015-03-04 02:12:10,393 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(376)) - Saving query unit: hdfs://localhost:58237/tmp/tajo-jenkins/staging/history/20150304/query-detail/q_1425434618483_0477/eb_1425434618483_0477_000002.hist 2015-03-04 02:12:10,396 INFO: BlockStateChange (logAddStoredBlock(2339)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40274 is added to blk_1073744559_3735{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e9ba800-2b88-46aa-abf9-f97b80843a3a:NORMAL|RBW]]} size 0 2015-03-04 02:12:10,399 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(376)) - Saving query unit: hdfs://localhost:58237/tmp/tajo-jenkins/staging/history/20150304/query-detail/q_1425434618483_0477/eb_1425434618483_0477_000005.hist 2015-03-04 02:12:10,402 INFO: BlockStateChange (logAddStoredBlock(2339)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40274 is added to blk_1073744560_3736{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-bc2b6c9f-6544-4884-b136-f5bdad3a082a:NORMAL|RBW]]} size 0 2015-03-04 02:12:10,404 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(376)) - Saving query unit: hdfs://localhost:58237/tmp/tajo-jenkins/staging/history/20150304/query-detail/q_1425434618483_0477/eb_1425434618483_0477_000003.hist 2015-03-04 02:12:10,407 INFO: BlockStateChange (logAddStoredBlock(2339)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40274 is added to blk_1073744561_3737{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e9ba800-2b88-46aa-abf9-f97b80843a3a:NORMAL|RBW]]} size 2 Killed Results : Tests run: 578, Failures: 0, Errors: 0, Skipped: 0 [INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Tajo Main ......................................... SUCCESS [ 2.017 s] [INFO] Tajo Project POM .................................. SUCCESS [ 2.061 s] [INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.831 s] [INFO] Tajo Common ....................................... SUCCESS [ 29.176 s] [INFO] Tajo Algebra ...................................... SUCCESS [ 2.688 s] [INFO] Tajo Catalog Common ............................... SUCCESS [ 7.223 s] [INFO] Tajo Plan ......................................... SUCCESS [ 6.797 s] [INFO] Tajo Rpc .......................................... SUCCESS [ 23.495 s] [INFO] Tajo Catalog Client ............................... SUCCESS [ 1.130 s] [INFO] Tajo Catalog Server ............................... SUCCESS [ 11.200 s] [INFO] Tajo Storage Common ............................... SUCCESS [ 11.235 s] [INFO] Tajo HDFS Storage ................................. SUCCESS [ 43.908 s] [INFO] Tajo HBase Storage ................................ SUCCESS [ 3.966 s] [INFO] Tajo PullServer ................................... SUCCESS [ 0.981 s] [INFO] Tajo Client ....................................... SUCCESS [ 3.807 s] [INFO] Tajo CLI tools .................................... SUCCESS [ 1.998 s] [INFO] Tajo JDBC Driver .................................. SUCCESS [ 3.191 s] [INFO] ASM (thirdparty) .................................. SUCCESS [ 1.840 s] [INFO] Tajo Core ......................................... FAILURE [09:13 min] [INFO] Tajo Catalog Drivers HCatalog ..................... SKIPPED [INFO] Tajo Catalog Drivers .............................. SKIPPED [INFO] Tajo Catalog ...................................... SKIPPED [INFO] Tajo Storage ...................................... SKIPPED [INFO] Tajo Distribution ................................. SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 11:55 min [INFO] Finished at: 2015-03-04T02:12:10+00:00 [INFO] Final Memory: 93M/717M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was /bin/sh -c cd <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core> && /home/jenkins/tools/java/jdk1.6.0_45-64/jre/bin/java -Xms512m -Xmx1024m -XX:MaxPermSize=128m -Dfile.encoding=UTF-8 -jar <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/surefire/surefirebooter8363499324061883183.jar> <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/surefire/surefire2527566465521745318tmp> <https://builds.apache.org/job/Tajo-master-nightly/ws/tajo-core/target/surefire/surefire_105983177691026624918tmp> [ERROR] -> [Help 1] [ERROR] [ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch. [ERROR] Re-run Maven using the -X switch to enable full debug logging. [ERROR] [ERROR] For more information about the errors and possible solutions, please read the following articles: [ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/PluginExecutionException [ERROR] [ERROR] After correcting the problems, you can resume the build with the command [ERROR] mvn <goals> -rf :tajo-core Build step 'Execute shell' marked build as failure Archiving artifacts Sending artifact delta relative to Tajo-master-nightly #633 Archived 1 artifacts Archive block size is 32768 Received 0 blocks and 38187606 bytes Compression is 0.0% Took 12 sec Recording test results
