See <https://builds.apache.org/job/Tajo-master-build/188/changes>
Changes: [hyunsik] TAJO-777: Partition column in function parameter occurs NPE. (Hyoungjun Kim via hyunsik) ------------------------------------------ [...truncated 104526 lines...] 2014-04-21 02:45:52,372 INFO worker.TaskRunner (TaskRunner.java:stop(227)) - Stop TaskRunner: eb_1398048114608_0256_000001 2014-04-21 02:45:52,373 INFO worker.TaskRunnerManager (TaskRunnerManager.java:stopTask(89)) - Stop Task:eb_1398048114608_0256_000001,container_1398048114608_0256_01_001050 2014-04-21 02:45:52,373 INFO querymaster.Query (Query.java:handle(681)) - Processing q_1398048114608_0256 of type SUBQUERY_COMPLETED 2014-04-21 02:45:52,373 INFO querymaster.SubQuery (SubQuery.java:calculateShuffleOutputNum(726)) - eb_1398048114608_0256_000002, Outer volume: 1.0MB, Inner volume: 1.0MB 2014-04-21 02:45:52,373 INFO querymaster.SubQuery (SubQuery.java:calculateShuffleOutputNum(732)) - eb_1398048114608_0256_000002, Bigger Table's volume is approximately 1 MB 2014-04-21 02:45:52,373 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 0.5,512 2014-04-21 02:45:52,374 INFO querymaster.SubQuery (SubQuery.java:calculateShuffleOutputNum(738)) - eb_1398048114608_0256_000002, Total memory of cluster is 1024 MB 2014-04-21 02:45:52,374 INFO querymaster.SubQuery (SubQuery.java:calculateShuffleOutputNum(743)) - eb_1398048114608_0256_000002, The determined number of join partitions is 1 2014-04-21 02:45:52,374 INFO querymaster.SubQuery (SubQuery.java:initTaskScheduler(668)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1398048114608_0256_000002 2014-04-21 02:45:52,378 INFO storage.AbstractStorageManager (AbstractStorageManager.java:listStatus(386)) - Total input paths to process : 1 2014-04-21 02:45:52,379 INFO storage.AbstractStorageManager (AbstractStorageManager.java:getSplits(615)) - Total # of splits: 1 2014-04-21 02:45:52,380 INFO querymaster.SubQuery (SubQuery.java:transition(638)) - 1 objects are scheduled 2014-04-21 02:45:52,380 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:start(88)) - Start TaskScheduler 2014-04-21 02:45:52,380 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1 2014-04-21 02:45:52,380 INFO querymaster.SubQuery (SubQuery.java:allocateContainers(857)) - Request Container for eb_1398048114608_0256_000002 containers=1 2014-04-21 02:45:52,380 INFO querymaster.Query (Query.java:executeNextBlock(602)) - Scheduling SubQuery:eb_1398048114608_0256_000002 2014-04-21 02:45:52,381 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(217)) - Start TajoWorkerAllocationThread 2014-04-21 02:45:52,382 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(336)) - Stop TajoWorkerAllocationThread 2014-04-21 02:45:52,382 INFO querymaster.SubQuery (SubQuery.java:transition(965)) - SubQuery (eb_1398048114608_0256_000002) has 1 containers! 2014-04-21 02:45:52,384 INFO worker.TaskRunner (TaskRunner.java:<init>(123)) - Tajo Root Dir: hdfs://localhost:45684/tajo 2014-04-21 02:45:52,384 INFO worker.TaskRunner (TaskRunner.java:<init>(124)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir> 2014-04-21 02:45:52,384 INFO worker.TaskRunner (TaskRunner.java:<init>(138)) - QueryMaster Address:asf011.sp2.ygridcore.net/67.195.138.20:15184 2014-04-21 02:45:52,384 INFO worker.TaskRunnerManager (TaskRunnerManager.java:run(188)) - Start TaskRunner:eb_1398048114608_0256_000002,container_1398048114608_0256_01_001051 2014-04-21 02:45:52,386 INFO worker.TaskRunner (TaskRunner.java:init(185)) - TaskRunner basedir is created (q_1398048114608_0256/output/2) 2014-04-21 02:45:52,387 INFO worker.TaskRunner (TaskRunner.java:run(312)) - TaskRunner startup 2014-04-21 02:45:52,387 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000002,container_1398048114608_0256_01_001051 2014-04-21 02:45:52,389 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:allocateRackTask(709)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: 67.195.138.20 2014-04-21 02:45:52,390 INFO worker.TaskRunner (TaskRunner.java:run(370)) - Accumulated Received Task: 1 2014-04-21 02:45:52,390 INFO worker.TaskRunner (TaskRunner.java:run(379)) - Initializing: ta_1398048114608_0256_000002_000000_00 2014-04-21 02:45:52,391 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000002_000000_00 is changed to TA_PENDING 2014-04-21 02:45:52,391 INFO worker.Task (Task.java:<init>(188)) - ================================== 2014-04-21 02:45:52,391 INFO worker.Task (Task.java:<init>(189)) - * Subquery ta_1398048114608_0256_000002_000000_00 is initialized 2014-04-21 02:45:52,391 INFO worker.Task (Task.java:<init>(190)) - * InterQuery: true, Use HASH_SHUFFLE shuffle 2014-04-21 02:45:52,391 INFO worker.Task (Task.java:<init>(193)) - * Fragments (num: 1) 2014-04-21 02:45:52,391 INFO worker.Task (Task.java:<init>(194)) - * Fetches (total:0) : 2014-04-21 02:45:52,392 INFO worker.Task (Task.java:<init>(198)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output/2/0_0> 2014-04-21 02:45:52,392 INFO worker.Task (Task.java:<init>(203)) - ================================== 2014-04-21 02:45:52,392 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000002_000000_00 is changed to TA_RUNNING 2014-04-21 02:45:52,398 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000002_000000_00 is changed to TA_SUCCEEDED 2014-04-21 02:45:52,398 INFO worker.Task (Task.java:run(447)) - Task Counter - total:720, succeeded: 719, killed: 1, failed: 0 2014-04-21 02:45:52,398 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000002,container_1398048114608_0256_01_001051 2014-04-21 02:45:52,399 INFO querymaster.SubQuery (SubQuery.java:transition(1042)) - [eb_1398048114608_0256_000002] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0 2014-04-21 02:45:52,399 INFO querymaster.SubQuery (SubQuery.java:transition(1082)) - subQuery completed - eb_1398048114608_0256_000002 (total=1, success=1, killed=0) 2014-04-21 02:45:52,399 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped 2014-04-21 02:45:52,399 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped 2014-04-21 02:45:52,399 INFO querymaster.Query (Query.java:handle(681)) - Processing q_1398048114608_0256 of type SUBQUERY_COMPLETED 2014-04-21 02:45:52,399 INFO worker.TaskRunner (TaskRunner.java:run(362)) - Received ShouldDie flag:eb_1398048114608_0256_000002,container_1398048114608_0256_01_001051 2014-04-21 02:45:52,400 INFO worker.TaskRunner (TaskRunner.java:stop(227)) - Stop TaskRunner: eb_1398048114608_0256_000002 2014-04-21 02:45:52,400 INFO querymaster.SubQuery (SubQuery.java:initTaskScheduler(668)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1398048114608_0256_000003 2014-04-21 02:45:52,400 INFO worker.TaskRunnerManager (TaskRunnerManager.java:stopTask(89)) - Stop Task:eb_1398048114608_0256_000002,container_1398048114608_0256_01_001051 2014-04-21 02:45:52,400 INFO querymaster.Repartitioner (Repartitioner.java:scheduleFragmentsForJoinQuery(149)) - [Distributed Join Strategy] : Symmetric Repartition Join 2014-04-21 02:45:52,401 INFO querymaster.Repartitioner (Repartitioner.java:scheduleFragmentsForJoinQuery(211)) - Larger intermediate data is approximately 1 MB 2014-04-21 02:45:52,401 INFO querymaster.Repartitioner (Repartitioner.java:scheduleFragmentsForJoinQuery(214)) - The calculated number of tasks is 1 2014-04-21 02:45:52,401 INFO querymaster.Repartitioner (Repartitioner.java:scheduleFragmentsForJoinQuery(215)) - The number of total shuffle keys is 1 2014-04-21 02:45:52,401 INFO querymaster.Repartitioner (Repartitioner.java:scheduleFragmentsForJoinQuery(219)) - The determined number of join tasks is 1 2014-04-21 02:45:52,401 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 0.5,512 2014-04-21 02:45:52,401 INFO querymaster.SubQuery (SubQuery.java:transition(638)) - 1 objects are scheduled 2014-04-21 02:45:52,402 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:start(88)) - Start TaskScheduler 2014-04-21 02:45:52,402 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1 2014-04-21 02:45:52,402 INFO querymaster.SubQuery (SubQuery.java:allocateContainers(857)) - Request Container for eb_1398048114608_0256_000003 containers=1 2014-04-21 02:45:52,402 INFO querymaster.Query (Query.java:executeNextBlock(602)) - Scheduling SubQuery:eb_1398048114608_0256_000003 2014-04-21 02:45:52,403 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(217)) - Start TajoWorkerAllocationThread 2014-04-21 02:45:52,403 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(336)) - Stop TajoWorkerAllocationThread 2014-04-21 02:45:52,404 INFO querymaster.SubQuery (SubQuery.java:transition(965)) - SubQuery (eb_1398048114608_0256_000003) has 1 containers! 2014-04-21 02:45:52,405 INFO worker.TaskRunner (TaskRunner.java:<init>(123)) - Tajo Root Dir: hdfs://localhost:45684/tajo 2014-04-21 02:45:52,405 INFO worker.TaskRunner (TaskRunner.java:<init>(124)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir> 2014-04-21 02:45:52,405 INFO worker.TaskRunner (TaskRunner.java:<init>(138)) - QueryMaster Address:asf011.sp2.ygridcore.net/67.195.138.20:15184 2014-04-21 02:45:52,406 INFO worker.TaskRunnerManager (TaskRunnerManager.java:run(188)) - Start TaskRunner:eb_1398048114608_0256_000003,container_1398048114608_0256_01_001052 2014-04-21 02:45:52,406 INFO worker.TaskRunner (TaskRunner.java:init(185)) - TaskRunner basedir is created (q_1398048114608_0256/output/3) 2014-04-21 02:45:52,407 INFO worker.TaskRunner (TaskRunner.java:run(312)) - TaskRunner startup 2014-04-21 02:45:52,407 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000003,container_1398048114608_0256_01_001052 2014-04-21 02:45:52,425 INFO worker.TaskRunner (TaskRunner.java:run(370)) - Accumulated Received Task: 1 2014-04-21 02:45:52,425 INFO worker.TaskRunner (TaskRunner.java:run(379)) - Initializing: ta_1398048114608_0256_000003_000000_00 2014-04-21 02:45:52,427 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000003_000000_00 is changed to TA_PENDING 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(188)) - ================================== 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(189)) - * Subquery ta_1398048114608_0256_000003_000000_00 is initialized 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(190)) - * InterQuery: true, Use HASH_SHUFFLE shuffle 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(193)) - * Fragments (num: 4) 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(194)) - * Fetches (total:2) : 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(196)) - Table Id: eb_1398048114608_0256_000002, url: http://67.195.138.20:44324/?qid=q_1398048114608_0256&sid=2&p=0&type=h&ta=0_0 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(196)) - Table Id: eb_1398048114608_0256_000001, url: http://67.195.138.20:44324/?qid=q_1398048114608_0256&sid=1&p=0&type=h&ta=0_0 2014-04-21 02:45:52,427 INFO worker.Task (Task.java:<init>(198)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output/3/0_0> 2014-04-21 02:45:52,428 INFO worker.Task (Task.java:<init>(203)) - ================================== 2014-04-21 02:45:52,430 INFO worker.Task (Task.java:init(219)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/in/eb_1398048114608_0256_000003/0/0/eb_1398048114608_0256_000001> 2014-04-21 02:45:52,431 INFO worker.Task (Task.java:init(219)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/in/eb_1398048114608_0256_000003/0/0/eb_1398048114608_0256_000002> 2014-04-21 02:45:52,433 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000003_000000_00 is changed to TA_RUNNING 2014-04-21 02:45:52,433 INFO pullserver.TajoPullServerService (TajoPullServerService.java:channelOpen(349)) - Current number of shuffle connections (2) 2014-04-21 02:45:52,433 INFO worker.Fetcher (Fetcher.java:get(129)) - Fetch: http://67.195.138.20:44324/?qid=q_1398048114608_0256&sid=1&p=0&type=h&ta=0_0 2014-04-21 02:45:52,433 INFO pullserver.TajoPullServerService (TajoPullServerService.java:channelOpen(349)) - Current number of shuffle connections (3) 2014-04-21 02:45:52,433 INFO worker.Fetcher (Fetcher.java:get(129)) - Fetch: http://67.195.138.20:44324/?qid=q_1398048114608_0256&sid=2&p=0&type=h&ta=0_0 2014-04-21 02:45:52,434 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(394)) - PullServer request param: shuffleType=h, sid=1, partId=0, taskIds=[0_0] 2014-04-21 02:45:52,434 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(400)) - PullServer baseDir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output> 2014-04-21 02:45:52,434 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(394)) - PullServer request param: shuffleType=h, sid=2, partId=0, taskIds=[0_0] 2014-04-21 02:45:52,435 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(400)) - PullServer baseDir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output> 2014-04-21 02:45:52,435 INFO worker.Task (Task.java:waitForFetch(356)) - ta_1398048114608_0256_000003_000000_00 All fetches are done! 2014-04-21 02:45:52,437 INFO planner.PhysicalPlannerImpl (PhysicalPlannerImpl.java:checkIfInMemoryInnerJoinIsPossible(245)) - [ta_1398048114608_0256_000003_000000_00] the volume of Left relations (eb_1398048114608_0256_000001) is 120 B and is fit to main maemory. 2014-04-21 02:45:52,437 INFO planner.PhysicalPlannerImpl (PhysicalPlannerImpl.java:createBestInnerJoinPlan(398)) - Join (7) chooses [In-memory Hash Join] 2014-04-21 02:45:52,438 INFO planner.PhysicalPlannerImpl (PhysicalPlannerImpl.java:switchJoinSidesIfNecessary(378)) - [ta_1398048114608_0256_000003_000000_00] Right relations eb_1398048114608_0256_000002 (91 B) is smaller than Left relations eb_1398048114608_0256_000001 (120 B). 2014-04-21 02:45:52,438 INFO planner.PhysicalPlannerImpl (PhysicalPlannerImpl.java:createInMemoryHashAggregation(901)) - The planner chooses [Hash Aggregation] 2014-04-21 02:45:52,441 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000003_000000_00 is changed to TA_SUCCEEDED 2014-04-21 02:45:52,441 INFO worker.Task (Task.java:run(447)) - Task Counter - total:721, succeeded: 720, killed: 1, failed: 0 2014-04-21 02:45:52,442 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000003,container_1398048114608_0256_01_001052 2014-04-21 02:45:52,442 INFO querymaster.SubQuery (SubQuery.java:transition(1042)) - [eb_1398048114608_0256_000003] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0 2014-04-21 02:45:52,442 INFO querymaster.SubQuery (SubQuery.java:transition(1082)) - subQuery completed - eb_1398048114608_0256_000003 (total=1, success=1, killed=0) 2014-04-21 02:45:52,442 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped 2014-04-21 02:45:52,442 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped 2014-04-21 02:45:52,443 INFO worker.TaskRunner (TaskRunner.java:run(362)) - Received ShouldDie flag:eb_1398048114608_0256_000003,container_1398048114608_0256_01_001052 2014-04-21 02:45:52,443 INFO querymaster.Query (Query.java:handle(681)) - Processing q_1398048114608_0256 of type SUBQUERY_COMPLETED 2014-04-21 02:45:52,443 INFO worker.TaskRunner (TaskRunner.java:stop(227)) - Stop TaskRunner: eb_1398048114608_0256_000003 2014-04-21 02:45:52,443 INFO worker.TaskRunnerManager (TaskRunnerManager.java:stopTask(89)) - Stop Task:eb_1398048114608_0256_000003,container_1398048114608_0256_01_001052 2014-04-21 02:45:52,443 INFO querymaster.SubQuery (SubQuery.java:initTaskScheduler(668)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1398048114608_0256_000004 2014-04-21 02:45:52,443 INFO querymaster.SubQuery (SubQuery.java:getNonLeafTaskNum(806)) - Table's volume is approximately 1 MB 2014-04-21 02:45:52,443 INFO querymaster.SubQuery (SubQuery.java:getNonLeafTaskNum(809)) - The determined number of non-leaf tasks is 1 2014-04-21 02:45:52,444 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 0.5,512 2014-04-21 02:45:52,444 INFO querymaster.Repartitioner (Repartitioner.java:scheduleHashShuffledFetches(515)) - eb_1398048114608_0256_000004, ScheduleHashShuffledFetches - Max num=1, finalFetchURI=1 2014-04-21 02:45:52,444 INFO querymaster.Repartitioner (Repartitioner.java:scheduleHashShuffledFetches(518)) - eb_1398048114608_0256_000004, No Grouping Column - determinedTaskNum is set to 1 2014-04-21 02:45:52,444 INFO querymaster.Repartitioner (Repartitioner.java:scheduleHashShuffledFetches(525)) - eb_1398048114608_0256_000004, DeterminedTaskNum : 1 2014-04-21 02:45:52,444 INFO querymaster.SubQuery (SubQuery.java:transition(638)) - 1 objects are scheduled 2014-04-21 02:45:52,445 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:start(88)) - Start TaskScheduler 2014-04-21 02:45:52,445 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1 2014-04-21 02:45:52,445 INFO querymaster.SubQuery (SubQuery.java:allocateContainers(857)) - Request Container for eb_1398048114608_0256_000004 containers=1 2014-04-21 02:45:52,445 INFO querymaster.Query (Query.java:executeNextBlock(602)) - Scheduling SubQuery:eb_1398048114608_0256_000004 2014-04-21 02:45:52,445 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(217)) - Start TajoWorkerAllocationThread 2014-04-21 02:45:52,446 INFO worker.TajoResourceAllocator (TajoResourceAllocator.java:run(336)) - Stop TajoWorkerAllocationThread 2014-04-21 02:45:52,447 INFO querymaster.SubQuery (SubQuery.java:transition(965)) - SubQuery (eb_1398048114608_0256_000004) has 1 containers! 2014-04-21 02:45:52,448 INFO worker.TaskRunner (TaskRunner.java:<init>(123)) - Tajo Root Dir: hdfs://localhost:45684/tajo 2014-04-21 02:45:52,449 INFO worker.TaskRunner (TaskRunner.java:<init>(124)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir> 2014-04-21 02:45:52,449 INFO worker.TaskRunner (TaskRunner.java:<init>(138)) - QueryMaster Address:asf011.sp2.ygridcore.net/67.195.138.20:15184 2014-04-21 02:45:52,449 INFO worker.TaskRunnerManager (TaskRunnerManager.java:run(188)) - Start TaskRunner:eb_1398048114608_0256_000004,container_1398048114608_0256_01_001053 2014-04-21 02:45:52,450 INFO worker.TaskRunner (TaskRunner.java:init(185)) - TaskRunner basedir is created (q_1398048114608_0256/output/4) 2014-04-21 02:45:52,450 INFO worker.TaskRunner (TaskRunner.java:run(312)) - TaskRunner startup 2014-04-21 02:45:52,450 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000004,container_1398048114608_0256_01_001053 2014-04-21 02:45:52,452 INFO worker.TaskRunner (TaskRunner.java:run(370)) - Accumulated Received Task: 1 2014-04-21 02:45:52,452 INFO worker.TaskRunner (TaskRunner.java:run(379)) - Initializing: ta_1398048114608_0256_000004_000000_00 2014-04-21 02:45:52,454 INFO worker.Task (Task.java:<init>(183)) - Output File Path: hdfs://localhost:45684/tmp/tajo-jenkins/staging/q_1398048114608_0256/RESULT/part-04-000000 2014-04-21 02:45:52,454 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000004_000000_00 is changed to TA_PENDING 2014-04-21 02:45:52,454 INFO worker.Task (Task.java:<init>(188)) - ================================== 2014-04-21 02:45:52,454 INFO worker.Task (Task.java:<init>(189)) - * Subquery ta_1398048114608_0256_000004_000000_00 is initialized 2014-04-21 02:45:52,454 INFO worker.Task (Task.java:<init>(190)) - * InterQuery: false 2014-04-21 02:45:52,454 INFO worker.Task (Task.java:<init>(193)) - * Fragments (num: 1) 2014-04-21 02:45:52,455 INFO worker.Task (Task.java:<init>(194)) - * Fetches (total:1) : 2014-04-21 02:45:52,455 INFO worker.Task (Task.java:<init>(196)) - Table Id: eb_1398048114608_0256_000003, url: http://asf011.sp2.ygridcore.net:44324/?qid=q_1398048114608_0256&sid=3&p=0&type=h&ta=0_0 2014-04-21 02:45:52,455 INFO worker.Task (Task.java:<init>(198)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output/4/0_0> 2014-04-21 02:45:52,455 INFO worker.Task (Task.java:<init>(203)) - ================================== 2014-04-21 02:45:52,456 INFO worker.Task (Task.java:init(219)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/in/eb_1398048114608_0256_000004/0/0/eb_1398048114608_0256_000003> 2014-04-21 02:45:52,458 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000004_000000_00 is changed to TA_RUNNING 2014-04-21 02:45:52,459 INFO pullserver.TajoPullServerService (TajoPullServerService.java:channelOpen(349)) - Current number of shuffle connections (2) 2014-04-21 02:45:52,459 INFO worker.Fetcher (Fetcher.java:get(129)) - Fetch: http://asf011.sp2.ygridcore.net:44324/?qid=q_1398048114608_0256&sid=3&p=0&type=h&ta=0_0 2014-04-21 02:45:52,460 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(394)) - PullServer request param: shuffleType=h, sid=3, partId=0, taskIds=[0_0] 2014-04-21 02:45:52,460 INFO pullserver.TajoPullServerService (TajoPullServerService.java:messageReceived(400)) - PullServer baseDir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4f015948-be5a-4045-acb7-35be441ff57a/tajo-localdir/q_1398048114608_0256/output> 2014-04-21 02:45:52,461 INFO worker.Task (Task.java:waitForFetch(356)) - ta_1398048114608_0256_000004_000000_00 All fetches are done! 2014-04-21 02:45:52,462 INFO planner.PhysicalPlannerImpl (PhysicalPlannerImpl.java:createInMemoryHashAggregation(901)) - The planner chooses [Hash Aggregation] 2014-04-21 02:45:52,475 INFO BlockStateChange (BlockManager.java:logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55927 is added to blk_1073742157_1333{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-5ddeefc0-305f-4419-9c12-4ac21df275ae:NORMAL|RBW]]} size 0 2014-04-21 02:45:52,477 INFO worker.TaskAttemptContext (TaskAttemptContext.java:setState(110)) - Query status of ta_1398048114608_0256_000004_000000_00 is changed to TA_SUCCEEDED 2014-04-21 02:45:52,477 INFO worker.Task (Task.java:run(447)) - Task Counter - total:722, succeeded: 721, killed: 1, failed: 0 2014-04-21 02:45:52,478 INFO worker.TaskRunner (TaskRunner.java:run(332)) - Request GetTask: eb_1398048114608_0256_000004,container_1398048114608_0256_01_001053 2014-04-21 02:45:52,478 INFO querymaster.SubQuery (SubQuery.java:transition(1042)) - [eb_1398048114608_0256_000004] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0 2014-04-21 02:45:52,478 INFO querymaster.SubQuery (SubQuery.java:transition(1082)) - subQuery completed - eb_1398048114608_0256_000004 (total=1, success=1, killed=0) 2014-04-21 02:45:52,478 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped 2014-04-21 02:45:52,479 INFO worker.TaskRunner (TaskRunner.java:run(362)) - Received ShouldDie flag:eb_1398048114608_0256_000004,container_1398048114608_0256_01_001053 2014-04-21 02:45:52,479 INFO worker.TaskRunner (TaskRunner.java:stop(227)) - Stop TaskRunner: eb_1398048114608_0256_000004 2014-04-21 02:45:52,479 INFO querymaster.Query (Query.java:handle(681)) - Processing q_1398048114608_0256 of type SUBQUERY_COMPLETED 2014-04-21 02:45:52,479 INFO querymaster.Query (Query.java:handle(681)) - Processing q_1398048114608_0256 of type QUERY_COMPLETED 2014-04-21 02:45:52,479 INFO master.DefaultTaskScheduler (DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped 2014-04-21 02:45:52,479 INFO worker.TaskRunnerManager (TaskRunnerManager.java:stopTask(89)) - Stop Task:eb_1398048114608_0256_000004,container_1398048114608_0256_01_001053 2014-04-21 02:45:52,480 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 0.5,512 2014-04-21 02:45:52,480 INFO querymaster.Query (Query.java:handle(694)) - q_1398048114608_0256 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED 2014-04-21 02:45:52,480 INFO querymaster.QueryMasterTask (QueryMasterTask.java:handle(278)) - Query completion notified from q_1398048114608_0256 2014-04-21 02:45:52,480 INFO querymaster.QueryMasterTask (QueryMasterTask.java:handle(289)) - Query final state: QUERY_SUCCEEDED 2014-04-21 02:45:52,480 INFO querymaster.QueryMasterTask (QueryMasterTask.java:stop(182)) - Stopping QueryMasterTask:q_1398048114608_0256 2014-04-21 02:45:52,481 INFO querymaster.QueryJobManager (QueryJobManager.java:stopQuery(146)) - Stop QueryInProgress:q_1398048114608_0256 2014-04-21 02:45:52,481 INFO querymaster.QueryInProgress (QueryInProgress.java:stop(113)) - ========================================================= 2014-04-21 02:45:52,481 INFO querymaster.QueryInProgress (QueryInProgress.java:stop(114)) - Stop query:q_1398048114608_0256 2014-04-21 02:45:52,481 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 0.0,512 2014-04-21 02:45:52,481 INFO querymaster.QueryInProgress (QueryInProgress.java:heartbeat(263)) - Received QueryMaster heartbeat:q_1398048114608_0256state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf011.sp2.ygridcore.net 2014-04-21 02:45:52,481 INFO rm.TajoWorkerResourceManager (TajoWorkerResourceManager.java:stopQueryMaster(534)) - Released QueryMaster (q_1398048114608_0256) resource:null 2014-04-21 02:45:52,482 INFO querymaster.QueryInProgress (QueryInProgress.java:stop(122)) - q_1398048114608_0256 QueryMaster stopped 2014-04-21 02:45:52,483 INFO master.TajoAsyncDispatcher (TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1398048114608_0256 2014-04-21 02:45:52,484 WARN master.TajoAsyncDispatcher (TajoAsyncDispatcher.java:stop(115)) - Interrupted Exception while stopping 2014-04-21 02:45:52,484 INFO master.TajoAsyncDispatcher (TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher stopped:q_1398048114608_0256 2014-04-21 02:45:52,484 INFO querymaster.QueryMasterTask (QueryMasterTask.java:stop(210)) - Stopped QueryMasterTask:q_1398048114608_0256 2014-04-21 02:45:52,769 INFO worker.TajoWorkerClientService (TajoWorkerClientService.java:closeQuery(217)) - Stop Query:q_1398048114608_0256 2014-04-21 02:45:52,770 INFO session.SessionManager (SessionManager.java:removeSession(80)) - Session c7b66306-1255-424f-9cba-71f4004d8a20 is removed. Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.441 sec 2014-04-21 02:45:52,814 INFO worker.TajoWorker (TajoWorker.java:run(492)) - ============================================ 2014-04-21 02:45:52,814 INFO worker.TajoWorker (TajoWorker.java:run(493)) - TajoWorker received SIGINT Signal 2014-04-21 02:45:52,814 INFO worker.TajoWorker (TajoWorker.java:run(494)) - ============================================ 2014-04-21 02:45:52,816 INFO session.SessionManager (SessionManager.java:removeSession(80)) - Session edb64220-79f0-47a5-b13b-f6491c274848 is removed. 2014-04-21 02:45:52,816 INFO session.SessionManager (SessionManager.java:removeSession(80)) - Session 266389c2-1a27-4cce-8f78-3c9c4343d9b7 is removed. 2014-04-21 02:45:52,823 INFO worker.WorkerHeartbeatService (WorkerHeartbeatService.java:run(260)) - Worker Resource Heartbeat Thread stopped. 2014-04-21 02:45:52,838 INFO rpc.NettyServerBase (NettyServerBase.java:shutdown(127)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:15185) shutdown 2014-04-21 02:45:52,838 INFO worker.TajoWorkerManagerService (TajoWorkerManagerService.java:stop(95)) - TajoWorkerManagerService stopped 2014-04-21 02:45:52,840 INFO rpc.NettyServerBase (NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:15184) shutdown 2014-04-21 02:45:52,840 INFO querymaster.QueryMasterManagerService (QueryMasterManagerService.java:stop(111)) - QueryMasterManagerService stopped 2014-04-21 02:45:52,841 INFO querymaster.QueryMaster (QueryMaster.java:run(434)) - QueryMaster heartbeat thread stopped 2014-04-21 02:45:52,843 INFO master.TajoAsyncDispatcher (TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher stopped:querymaster_1398048115258 2014-04-21 02:45:52,844 INFO querymaster.QueryMaster (QueryMaster.java:stop(160)) - QueryMaster stop 2014-04-21 02:45:52,844 INFO worker.TajoWorkerClientService (TajoWorkerClientService.java:stop(107)) - TajoWorkerClientService stopping 2014-04-21 02:45:52,845 INFO rpc.NettyServerBase (NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:15183) shutdown 2014-04-21 02:45:52,845 INFO worker.TajoWorkerClientService (TajoWorkerClientService.java:stop(111)) - TajoWorkerClientService stopped 2014-04-21 02:45:52,846 INFO worker.TajoWorker (TajoWorker.java:stop(334)) - TajoWorker main thread exiting Results : Failed tests: testQueryCasesOnColumnPartitionedTable(org.apache.tajo.engine.query.TestTablePartitions): <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-classes/queries/TestTablePartitions/case4.sql> existence check Tests run: 694, Failures: 1, Errors: 0, Skipped: 0 [INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Tajo Main ......................................... SUCCESS [45.724s] [INFO] Tajo Project POM .................................. SUCCESS [4.877s] [INFO] Tajo Common ....................................... SUCCESS [12.841s] [INFO] Tajo Algebra ...................................... SUCCESS [4.439s] [INFO] Tajo Catalog Common ............................... SUCCESS [5.949s] [INFO] Tajo Rpc .......................................... SUCCESS [21.543s] [INFO] Tajo Catalog Client ............................... SUCCESS [1.275s] [INFO] Tajo Catalog Server ............................... SUCCESS [8.728s] [INFO] Tajo Storage ...................................... SUCCESS [1:00.486s] [INFO] Tajo Core PullServer .............................. SUCCESS [1.034s] [INFO] Tajo Client ....................................... SUCCESS [3.503s] [INFO] Tajo JDBC Driver .................................. SUCCESS [1.321s] [INFO] Tajo Core ......................................... FAILURE [4:23.666s] [INFO] Tajo Catalog Drivers .............................. SKIPPED [INFO] Tajo Catalog ...................................... SKIPPED [INFO] Tajo Distribution ................................. SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 7:16.384s [INFO] Finished at: Mon Apr 21 02:45:53 UTC 2014 [INFO] Final Memory: 42M/268M [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 Updating TAJO-777
