You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tajo.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/04/21 04:45:56 UTC
Build failed in Jenkins: Tajo-master-build #188
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
Jenkins build is back to normal : Tajo-master-build #189
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/189/changes>