See <https://builds.apache.org/job/Tajo-master-build/138/>

------------------------------------------
[...truncated 75277 lines...]
Execution Block Graph (TERMINAL - eb_1395895902741_0215_000005)
-------------------------------------------------------------------------------
|-eb_1395895902741_0215_000005
   |-eb_1395895902741_0215_000004
      |-eb_1395895902741_0215_000003
-------------------------------------------------------------------------------

=======================================================
Block Id: eb_1395895902741_0215_000003 [LEAF]
=======================================================

[Outgoing]
[q_1395895902741_0215] 3 => 4 (type=HASH_SHUFFLE, key=, num=1)

[Enforcers]
 0: type=Broadcast, tables=default.lineitem
 1: type=Broadcast, tables=default.part

GROUP_BY(9)()
  => exprs: (sum(?casewhen (FLOAT8)),sum(?multiply_2 (FLOAT8)))
  => target list: ?sum_6 (FLOAT8), ?sum_7 (FLOAT8)
  => out schema:{(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}
  => in schema:{(2) ?casewhen (FLOAT8),?multiply_2 (FLOAT8)}
   JOIN(7)(INNER)
     => Join Cond: default.lineitem.l_partkey (INT4) = default.part.p_partkey 
(INT4)
     => target list: CASE WHEN default.part.p_type (TEXT)LIKE'PROMO%' THEN 
default.lineitem.l_extendedprice (FLOAT8) ELSE 0.0 END as ?casewhen, 
?multiply_2 (FLOAT8)
     => out schema: {(2) ?casewhen (FLOAT8),?multiply_2 (FLOAT8)}
     => in schema: {(5) ?multiply_2 (FLOAT8),default.lineitem.l_partkey 
(INT4),default.lineitem.l_extendedprice (FLOAT8),default.part.p_partkey 
(INT4),default.part.p_type (TEXT)}
      SCAN(1) on default.part
        => target list: default.part.p_partkey (INT4), default.part.p_type 
(TEXT)
        => out schema: {(2) default.part.p_partkey (INT4),default.part.p_type 
(TEXT)}
        => in schema: {(9) default.part.p_partkey (INT4),default.part.p_name 
(TEXT),default.part.p_mfgr (TEXT),default.part.p_brand 
(TEXT),default.part.p_type (TEXT),default.part.p_size 
(INT4),default.part.p_container (TEXT),default.part.p_retailprice 
(FLOAT8),default.part.p_comment (TEXT)}
      SCAN(0) on default.lineitem
        => target list: default.lineitem.l_extendedprice (FLOAT8) * 1 - 
default.lineitem.l_discount (FLOAT8) as ?multiply_2, default.lineitem.l_partkey 
(INT4), default.lineitem.l_extendedprice (FLOAT8)
        => out schema: {(3) ?multiply_2 (FLOAT8),default.lineitem.l_partkey 
(INT4),default.lineitem.l_extendedprice (FLOAT8)}
        => in schema: {(16) default.lineitem.l_orderkey 
(INT4),default.lineitem.l_partkey (INT4),default.lineitem.l_suppkey 
(INT4),default.lineitem.l_linenumber (INT4),default.lineitem.l_quantity 
(FLOAT8),default.lineitem.l_extendedprice (FLOAT8),default.lineitem.l_discount 
(FLOAT8),default.lineitem.l_tax (FLOAT8),default.lineitem.l_returnflag 
(TEXT),default.lineitem.l_linestatus (TEXT),default.lineitem.l_shipdate 
(TEXT),default.lineitem.l_commitdate (TEXT),default.lineitem.l_receiptdate 
(TEXT),default.lineitem.l_shipinstruct (TEXT),default.lineitem.l_shipmode 
(TEXT),default.lineitem.l_comment (TEXT)}

=======================================================
Block Id: eb_1395895902741_0215_000004 [ROOT]
=======================================================

[Incoming]
[q_1395895902741_0215] 3 => 4 (type=HASH_SHUFFLE, key=, num=1)

PROJECTION(3)
  => Targets: 100 * ?sum_1 (FLOAT8) / ?sum_3 (FLOAT8) as promo_revenue
  => out schema: {(1) promo_revenue (FLOAT8)}
  => in  schema: {(2) ?sum_1 (FLOAT8),?sum_3 (FLOAT8)}
   GROUP_BY(5)()
     => exprs: (sum(?sum_6 (FLOAT8)),sum(?sum_7 (FLOAT8)))
     => target list: ?sum_1 (FLOAT8), ?sum_3 (FLOAT8)
     => out schema:{(2) ?sum_1 (FLOAT8),?sum_3 (FLOAT8)}
     => in schema:{(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}
      SCAN(10) on eb_1395895902741_0215_000003
        => out schema: {(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}
        => in schema: {(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}

=======================================================
Block Id: eb_1395895902741_0215_000005 [TERMINAL]
=======================================================

2014-03-27 04:54:56,011 INFO  master.TajoAsyncDispatcher 
(TajoAsyncDispatcher.java:start(101)) - AsyncDispatcher 
started:q_1395895902741_0215
2014-03-27 04:54:56,011 INFO  querymaster.Query (Query.java:handle(655)) - 
Processing q_1395895902741_0215 of type START
2014-03-27 04:54:56,011 INFO  querymaster.SubQuery 
(SubQuery.java:initTaskScheduler(668)) - 
org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling
2014-03-27 04:54:56,014 INFO  storage.AbstractStorageManager 
(AbstractStorageManager.java:listStatus(382)) - Total input paths to process : 1
2014-03-27 04:54:56,016 INFO  storage.AbstractStorageManager 
(AbstractStorageManager.java:getSplits(607)) - Total # of splits: 1
2014-03-27 04:54:56,017 INFO  storage.AbstractStorageManager 
(AbstractStorageManager.java:listStatus(382)) - Total input paths to process : 1
2014-03-27 04:54:56,019 INFO  storage.AbstractStorageManager 
(AbstractStorageManager.java:getSplits(607)) - Total # of splits: 1
2014-03-27 04:54:56,019 INFO  querymaster.Repartitioner 
(Repartitioner.java:scheduleFragmentsForJoinQuery(118)) - Left Volume: 368, 
Right Volume: 604
2014-03-27 04:54:56,019 INFO  querymaster.Repartitioner 
(Repartitioner.java:scheduleFragmentsForJoinQuery(134)) - [Distributed Join 
Strategy] : Immediate Two Way Join on Single Machine
2014-03-27 04:54:56,019 INFO  querymaster.SubQuery 
(SubQuery.java:transition(638)) - 2 objects are scheduled
2014-03-27 04:54:56,019 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:start(88)) - Start TaskScheduler
2014-03-27 04:54:56,020 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:calculateNumRequestContainers(99)) - 
CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-03-27 04:54:56,020 INFO  querymaster.SubQuery 
(SubQuery.java:allocateContainers(850)) - Request Container for 
eb_1395895902741_0215_000003 containers=1
2014-03-27 04:54:56,020 INFO  querymaster.Query (Query.java:handle(668)) - 
q_1395895902741_0215 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-03-27 04:54:56,020 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:run(216)) - Start TajoWorkerAllocationThread
2014-03-27 04:54:56,021 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:run(334)) - Stop TajoWorkerAllocationThread
2014-03-27 04:54:56,022 INFO  querymaster.SubQuery 
(SubQuery.java:transition(957)) - SubQuery (eb_1395895902741_0215_000003) has 1 
containers!
2014-03-27 04:54:56,023 INFO  worker.TaskRunner (TaskRunner.java:<init>(121)) - 
Tajo Root Dir: hdfs://localhost:53039/tajo
2014-03-27 04:54:56,023 INFO  worker.TaskRunner (TaskRunner.java:<init>(122)) - 
Worker Local Dir: 
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir>
2014-03-27 04:54:56,024 INFO  worker.TaskRunner (TaskRunner.java:<init>(136)) - 
QueryMaster Address:asf009.sp2.ygridcore.net/67.195.138.22:16834
2014-03-27 04:54:56,024 INFO  worker.TaskRunnerManager 
(TaskRunnerManager.java:run(188)) - Start 
TaskRunner:eb_1395895902741_0215_000003,container_1395895902741_0215_01_000804
2014-03-27 04:54:56,025 INFO  worker.TaskRunner (TaskRunner.java:init(183)) - 
TaskRunner basedir is created (q_1395895902741_0215/output/3)
2014-03-27 04:54:56,025 INFO  worker.TaskRunner (TaskRunner.java:run(316)) - 
TaskRunner startup
2014-03-27 04:54:56,026 INFO  worker.TaskRunner (TaskRunner.java:run(336)) - 
Request GetTask: 
eb_1395895902741_0215_000003,container_1395895902741_0215_01_000804
2014-03-27 04:54:56,027 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:allocateRackTask(702)) - Assigned Local/Rack/Total: 
(0/1/1), Locality: 0.00%, Rack host: 67.195.138.22
2014-03-27 04:54:56,030 INFO  worker.TaskRunner (TaskRunner.java:run(374)) - 
Accumulated Received Task: 1
2014-03-27 04:54:56,030 INFO  worker.TaskRunner (TaskRunner.java:run(383)) - 
Initializing: ta_1395895902741_0215_000003_000000_00
2014-03-27 04:54:56,033 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000003_000000_00 is changed to TA_PENDING
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(188)) - 
==================================
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(189)) - * Subquery 
ta_1395895902741_0215_000003_000000_00 is initialized
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(190)) - * 
InterQuery: true, Use HASH_SHUFFLE shuffle
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(193)) - * Fragments 
(num: 2)
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(194)) - * Fetches 
(total:0) :
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(198)) - * Local 
task dir: 
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir/q_1395895902741_0215/output/3/0_0>
2014-03-27 04:54:56,033 INFO  worker.Task (Task.java:<init>(203)) - 
==================================
2014-03-27 04:54:56,034 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000003_000000_00 is changed to TA_RUNNING
2014-03-27 04:54:56,034 INFO  planner.PhysicalPlannerImpl 
(PhysicalPlannerImpl.java:checkIfInMemoryInnerJoinIsPossible(245)) - 
[ta_1395895902741_0215_000003_000000_00] the volume of Left relations 
(default.lineitem) is 604 B and is fit to main maemory.
2014-03-27 04:54:56,034 INFO  planner.PhysicalPlannerImpl 
(PhysicalPlannerImpl.java:createBestInnerJoinPlan(398)) - Join (7) chooses 
[In-memory Hash Join]
2014-03-27 04:54:56,034 INFO  planner.PhysicalPlannerImpl 
(PhysicalPlannerImpl.java:switchJoinSidesIfNecessary(378)) - 
[ta_1395895902741_0215_000003_000000_00] Right relations default.part (368 B) 
is smaller than Left relations default.lineitem (604 B).
2014-03-27 04:54:56,034 INFO  planner.PhysicalPlannerImpl 
(PhysicalPlannerImpl.java:createInMemoryHashAggregation(898)) - The planner 
chooses [Hash Aggregation]
2014-03-27 04:54:56,044 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000003_000000_00 is changed to TA_SUCCEEDED
2014-03-27 04:54:56,044 INFO  worker.Task (Task.java:run(447)) - Task Counter - 
total:488, succeeded: 488, killed: 0, failed: 0
2014-03-27 04:54:56,045 INFO  worker.TaskRunner (TaskRunner.java:run(336)) - 
Request GetTask: 
eb_1395895902741_0215_000003,container_1395895902741_0215_01_000804
2014-03-27 04:54:56,045 INFO  querymaster.SubQuery 
(SubQuery.java:transition(1032)) - [eb_1395895902741_0215_000003] Task 
Completion Event (Total: 2, Success: 2, Killed: 0, Failed: 0
2014-03-27 04:54:56,045 INFO  querymaster.SubQuery 
(SubQuery.java:transition(1072)) - subQuery completed - 
eb_1395895902741_0215_000003 (total=2, success=2, killed=0)
2014-03-27 04:54:56,045 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped
2014-03-27 04:54:56,045 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped
2014-03-27 04:54:56,046 INFO  worker.TaskRunner (TaskRunner.java:run(366)) - 
Received ShouldDie 
flag:eb_1395895902741_0215_000003,container_1395895902741_0215_01_000804
2014-03-27 04:54:56,046 INFO  worker.TaskRunner (TaskRunner.java:stop(227)) - 
Stop TaskRunner: eb_1395895902741_0215_000003
2014-03-27 04:54:56,046 INFO  worker.TaskRunnerManager 
(TaskRunnerManager.java:stopTask(89)) - Stop 
Task:eb_1395895902741_0215_000003,container_1395895902741_0215_01_000804
2014-03-27 04:54:56,046 INFO  querymaster.Query (Query.java:handle(655)) - 
Processing q_1395895902741_0215 of type SUBQUERY_COMPLETED
2014-03-27 04:54:56,046 INFO  querymaster.SubQuery 
(SubQuery.java:initTaskScheduler(668)) - 
org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling
2014-03-27 04:54:56,046 INFO  querymaster.SubQuery 
(SubQuery.java:getNonLeafTaskNum(805)) - Table's volume is approximately 1 MB
2014-03-27 04:54:56,047 INFO  querymaster.SubQuery 
(SubQuery.java:getNonLeafTaskNum(808)) - The determined number of non-leaf 
tasks is 1
2014-03-27 04:54:56,047 INFO  rm.TajoWorkerResourceManager 
(TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 
1.0,512
2014-03-27 04:54:56,047 INFO  querymaster.Repartitioner 
(Repartitioner.java:scheduleHashShuffledFetches(484)) - 
ScheduleHashShuffledFetches - Max num=1, finalFetchURI=1
2014-03-27 04:54:56,047 INFO  querymaster.Repartitioner 
(Repartitioner.java:scheduleHashShuffledFetches(487)) - No Grouping Column - 
determinedTaskNum is set to 1
2014-03-27 04:54:56,048 INFO  querymaster.Repartitioner 
(Repartitioner.java:scheduleHashShuffledFetches(494)) - DeterminedTaskNum : 1
2014-03-27 04:54:56,048 INFO  querymaster.SubQuery 
(SubQuery.java:transition(638)) - 1 objects are scheduled
2014-03-27 04:54:56,048 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:start(88)) - Start TaskScheduler
2014-03-27 04:54:56,048 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:calculateNumRequestContainers(99)) - 
CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-03-27 04:54:56,048 INFO  querymaster.SubQuery 
(SubQuery.java:allocateContainers(850)) - Request Container for 
eb_1395895902741_0215_000004 containers=1
2014-03-27 04:54:56,048 INFO  querymaster.Query 
(Query.java:executeNextBlock(576)) - Scheduling 
SubQuery:eb_1395895902741_0215_000004
2014-03-27 04:54:56,049 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:run(216)) - Start TajoWorkerAllocationThread
2014-03-27 04:54:56,050 INFO  worker.TajoResourceAllocator 
(TajoResourceAllocator.java:run(334)) - Stop TajoWorkerAllocationThread
2014-03-27 04:54:56,050 INFO  querymaster.SubQuery 
(SubQuery.java:transition(957)) - SubQuery (eb_1395895902741_0215_000004) has 1 
containers!
2014-03-27 04:54:56,051 INFO  worker.TaskRunner (TaskRunner.java:<init>(121)) - 
Tajo Root Dir: hdfs://localhost:53039/tajo
2014-03-27 04:54:56,051 INFO  worker.TaskRunner (TaskRunner.java:<init>(122)) - 
Worker Local Dir: 
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir>
2014-03-27 04:54:56,051 INFO  worker.TaskRunner (TaskRunner.java:<init>(136)) - 
QueryMaster Address:asf009.sp2.ygridcore.net/67.195.138.22:16834
2014-03-27 04:54:56,052 INFO  worker.TaskRunnerManager 
(TaskRunnerManager.java:run(188)) - Start 
TaskRunner:eb_1395895902741_0215_000004,container_1395895902741_0215_01_000805
2014-03-27 04:54:56,052 INFO  worker.TaskRunner (TaskRunner.java:init(183)) - 
TaskRunner basedir is created (q_1395895902741_0215/output/4)
2014-03-27 04:54:56,053 INFO  worker.TaskRunner (TaskRunner.java:run(316)) - 
TaskRunner startup
2014-03-27 04:54:56,053 INFO  worker.TaskRunner (TaskRunner.java:run(336)) - 
Request GetTask: 
eb_1395895902741_0215_000004,container_1395895902741_0215_01_000805
2014-03-27 04:54:56,055 INFO  worker.TaskRunner (TaskRunner.java:run(374)) - 
Accumulated Received Task: 1
2014-03-27 04:54:56,055 INFO  worker.TaskRunner (TaskRunner.java:run(383)) - 
Initializing: ta_1395895902741_0215_000004_000000_00
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(183)) - Output File 
Path: 
hdfs://localhost:53039/tmp/tajo-jenkins/staging/q_1395895902741_0215/RESULT/part-04-000000
2014-03-27 04:54:56,057 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000004_000000_00 is changed to TA_PENDING
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(188)) - 
==================================
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(189)) - * Subquery 
ta_1395895902741_0215_000004_000000_00 is initialized
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(190)) - * 
InterQuery: false
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(193)) - * Fragments 
(num: 1)
2014-03-27 04:54:56,057 INFO  worker.Task (Task.java:<init>(194)) - * Fetches 
(total:1) :
2014-03-27 04:54:56,058 INFO  worker.Task (Task.java:<init>(196)) - Table Id: 
eb_1395895902741_0215_000003, url: 
http://67.195.138.22:37133/?qid=q_1395895902741_0215&sid=3&p=0&type=h&ta=0_0
2014-03-27 04:54:56,058 INFO  worker.Task (Task.java:<init>(198)) - * Local 
task dir: 
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir/q_1395895902741_0215/output/4/0_0>
2014-03-27 04:54:56,058 INFO  worker.Task (Task.java:<init>(203)) - 
==================================
2014-03-27 04:54:56,060 INFO  worker.Task (Task.java:init(219)) - the directory 
is created  
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir/q_1395895902741_0215/in/eb_1395895902741_0215_000004/0/0/eb_1395895902741_0215_000003>
2014-03-27 04:54:56,065 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000004_000000_00 is changed to TA_RUNNING
2014-03-27 04:54:56,066 INFO  pullserver.TajoPullServerService 
(TajoPullServerService.java:channelOpen(346)) - Current number of shuffle 
connections (2)
2014-03-27 04:54:56,066 INFO  worker.Fetcher (Fetcher.java:get(129)) - Fetch: 
http://67.195.138.22:37133/?qid=q_1395895902741_0215&sid=3&p=0&type=h&ta=0_0
2014-03-27 04:54:56,067 INFO  pullserver.TajoPullServerService 
(TajoPullServerService.java:messageReceived(391)) - PullServer request param: 
shuffleType=h, sid=3, partId=0, taskIds=[0_0]
2014-03-27 04:54:56,067 INFO  pullserver.TajoPullServerService 
(TajoPullServerService.java:messageReceived(397)) - PullServer baseDir: 
file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/target/test-data/e5f6bac3-e730-4147-b4eb-802ef7b579a1/tajo-localdir/q_1395895902741_0215/output>
2014-03-27 04:54:56,069 INFO  worker.Task (Task.java:waitForFetch(356)) - 
ta_1395895902741_0215_000004_000000_00 All fetches are done!
2014-03-27 04:54:56,070 INFO  planner.PhysicalPlannerImpl 
(PhysicalPlannerImpl.java:createInMemoryHashAggregation(898)) - The planner 
chooses [Hash Aggregation]
2014-03-27 04:54:56,080 INFO  BlockStateChange 
(BlockManager.java:logAddStoredBlock(2237)) - BLOCK* addStoredBlock: blockMap 
updated: 127.0.0.1:41200 is added to 
blk_1073742118_1294{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, 
replicas=[ReplicaUnderConstruction[127.0.0.1:41200|RBW]]} size 0
2014-03-27 04:54:56,082 INFO  worker.TaskAttemptContext 
(TaskAttemptContext.java:setState(110)) - Query status of 
ta_1395895902741_0215_000004_000000_00 is changed to TA_SUCCEEDED
2014-03-27 04:54:56,082 INFO  worker.Task (Task.java:run(447)) - Task Counter - 
total:489, succeeded: 489, killed: 0, failed: 0
2014-03-27 04:54:56,082 INFO  worker.TaskRunner (TaskRunner.java:run(336)) - 
Request GetTask: 
eb_1395895902741_0215_000004,container_1395895902741_0215_01_000805
2014-03-27 04:54:56,083 INFO  querymaster.SubQuery 
(SubQuery.java:transition(1032)) - [eb_1395895902741_0215_000004] Task 
Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0
2014-03-27 04:54:56,083 INFO  querymaster.SubQuery 
(SubQuery.java:transition(1072)) - subQuery completed - 
eb_1395895902741_0215_000004 (total=1, success=1, killed=0)
2014-03-27 04:54:56,083 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped
2014-03-27 04:54:56,084 INFO  worker.TaskRunner (TaskRunner.java:run(366)) - 
Received ShouldDie 
flag:eb_1395895902741_0215_000004,container_1395895902741_0215_01_000805
2014-03-27 04:54:56,083 INFO  master.DefaultTaskScheduler 
(DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped
2014-03-27 04:54:56,084 INFO  worker.TaskRunner (TaskRunner.java:stop(227)) - 
Stop TaskRunner: eb_1395895902741_0215_000004
2014-03-27 04:54:56,084 INFO  worker.TaskRunnerManager 
(TaskRunnerManager.java:stopTask(89)) - Stop 
Task:eb_1395895902741_0215_000004,container_1395895902741_0215_01_000805
2014-03-27 04:54:56,084 INFO  querymaster.Query (Query.java:handle(655)) - 
Processing q_1395895902741_0215 of type SUBQUERY_COMPLETED
2014-03-27 04:54:56,084 INFO  querymaster.Query (Query.java:handle(655)) - 
Processing q_1395895902741_0215 of type QUERY_COMPLETED
2014-03-27 04:54:56,085 INFO  rm.TajoWorkerResourceManager 
(TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 
1.0,512
2014-03-27 04:54:56,085 INFO  querymaster.Query (Query.java:handle(668)) - 
q_1395895902741_0215 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-03-27 04:54:56,086 INFO  querymaster.QueryMasterTask 
(QueryMasterTask.java:handle(272)) - Query completion notified from 
q_1395895902741_0215
2014-03-27 04:54:56,086 INFO  querymaster.QueryMasterTask 
(QueryMasterTask.java:handle(283)) - Query final state: QUERY_SUCCEEDED
2014-03-27 04:54:56,086 INFO  querymaster.QueryMasterTask 
(QueryMasterTask.java:stop(178)) - Stopping QueryMasterTask:q_1395895902741_0215
2014-03-27 04:54:56,086 INFO  querymaster.QueryJobManager 
(QueryJobManager.java:stopQuery(140)) - Stop 
QueryInProgress:q_1395895902741_0215
2014-03-27 04:54:56,086 INFO  querymaster.QueryInProgress 
(QueryInProgress.java:heartbeat(263)) - Received QueryMaster 
heartbeat:q_1395895902741_0215state=QUERY_SUCCEEDED,progress=1.0, 
queryMaster=asf009.sp2.ygridcore.net
2014-03-27 04:54:56,086 INFO  querymaster.QueryInProgress 
(QueryInProgress.java:stop(113)) - 
=========================================================
2014-03-27 04:54:56,087 INFO  querymaster.QueryInProgress 
(QueryInProgress.java:stop(114)) - Stop query:q_1395895902741_0215
2014-03-27 04:54:56,087 INFO  rm.TajoWorkerResourceManager 
(TajoWorkerResourceManager.java:releaseWorkerResource(512)) - Release Resource: 
0.0,512
2014-03-27 04:54:56,087 INFO  rm.TajoWorkerResourceManager 
(TajoWorkerResourceManager.java:stopQueryMaster(534)) - Released QueryMaster 
(q_1395895902741_0215) resource:null
2014-03-27 04:54:56,087 INFO  querymaster.QueryInProgress 
(QueryInProgress.java:stop(122)) - q_1395895902741_0215 QueryMaster stopped
2014-03-27 04:54:56,088 INFO  master.TajoAsyncDispatcher 
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher 
stopped:QueryInProgress:q_1395895902741_0215
2014-03-27 04:54:56,088 WARN  master.TajoAsyncDispatcher 
(TajoAsyncDispatcher.java:stop(115)) - Interrupted Exception while stopping
2014-03-27 04:54:56,088 INFO  master.TajoAsyncDispatcher 
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher 
stopped:q_1395895902741_0215
2014-03-27 04:54:56,089 INFO  querymaster.QueryMasterTask 
(QueryMasterTask.java:stop(206)) - Stopped QueryMasterTask:q_1395895902741_0215
2014-03-27 04:54:56,427 INFO  worker.TajoWorkerClientService 
(TajoWorkerClientService.java:closeQuery(211)) - Stop Query:q_1395895902741_0215
2014-03-27 04:54:56,428 INFO  session.SessionManager 
(SessionManager.java:removeSession(80)) - Session 
24b62d35-6506-492e-b1e7-7b049b7a4ae0 is removed.
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.381 sec
2014-03-27 04:54:56,432 INFO  worker.TajoWorker (TajoWorker.java:run(492)) - 
============================================
2014-03-27 04:54:56,432 INFO  worker.TajoWorker (TajoWorker.java:run(493)) - 
TajoWorker received SIGINT Signal
2014-03-27 04:54:56,433 INFO  worker.TajoWorker (TajoWorker.java:run(494)) - 
============================================
2014-03-27 04:54:56,437 INFO  worker.WorkerHeartbeatService 
(WorkerHeartbeatService.java:run(251)) - Worker Resource Heartbeat Thread 
stopped.
2014-03-27 04:54:56,454 INFO  rpc.NettyServerBase 
(NettyServerBase.java:shutdown(127)) - Rpc (TajoWorkerProtocol) listened on 
0:0:0:0:0:0:0:0:16835) shutdown
2014-03-27 04:54:56,460 INFO  worker.TajoWorkerManagerService 
(TajoWorkerManagerService.java:stop(95)) - TajoWorkerManagerService stopped
2014-03-27 04:54:56,462 INFO  rpc.NettyServerBase 
(NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterProtocol) listened on 
0:0:0:0:0:0:0:0:16834) shutdown
2014-03-27 04:54:56,462 INFO  querymaster.QueryMasterManagerService 
(QueryMasterManagerService.java:stop(111)) - QueryMasterManagerService stopped
2014-03-27 04:54:56,463 INFO  querymaster.QueryMaster 
(QueryMaster.java:run(423)) - QueryMaster heartbeat thread stopped
2014-03-27 04:54:56,463 INFO  master.TajoAsyncDispatcher 
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher 
stopped:querymaster_1395895903444
2014-03-27 04:54:56,464 INFO  querymaster.QueryMaster 
(QueryMaster.java:stop(160)) - QueryMaster stop
2014-03-27 04:54:56,464 INFO  worker.TajoWorkerClientService 
(TajoWorkerClientService.java:stop(107)) - TajoWorkerClientService stopping
2014-03-27 04:54:56,465 INFO  rpc.NettyServerBase 
(NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterClientProtocol) listened 
on 0:0:0:0:0:0:0:0:16833) shutdown
2014-03-27 04:54:56,465 INFO  worker.TajoWorkerClientService 
(TajoWorkerClientService.java:stop(111)) - TajoWorkerClientService stopped
2014-03-27 04:54:56,465 INFO  worker.TajoWorker (TajoWorker.java:stop(334)) - 
TajoWorker main thread exiting

Results :

Failed tests:   testKillQuery(org.apache.tajo.client.TestTajoClient): 
expected:<QUERY_KILLED> but was:<QUERY_SUCCEEDED>

Tests run: 615, Failures: 1, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [17.052s]
[INFO] Tajo Project POM .................................. SUCCESS [0.905s]
[INFO] Tajo Common ....................................... SUCCESS [8.924s]
[INFO] Tajo Algebra ...................................... SUCCESS [2.371s]
[INFO] Tajo Rpc .......................................... SUCCESS [18.671s]
[INFO] Tajo Catalog Common ............................... SUCCESS [5.615s]
[INFO] Tajo Catalog Client ............................... SUCCESS [1.164s]
[INFO] Tajo Catalog Server ............................... SUCCESS [8.180s]
[INFO] Tajo Storage ...................................... SUCCESS [45.257s]
[INFO] Tajo Core PullServer .............................. SUCCESS [1.141s]
[INFO] Tajo Client ....................................... SUCCESS [3.351s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [0.562s]
[INFO] Tajo Core Backend ................................. FAILURE [3:38.382s]
[INFO] Tajo Core ......................................... SKIPPED
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 5:32.515s
[INFO] Finished at: Thu Mar 27 04:54:56 UTC 2014
[INFO] Final Memory: 39M/300M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal 
org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on 
project tajo-core-backend: There are test failures.
[ERROR] 
[ERROR] Please refer to 
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/tajo-core-backend/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-backend
Build step 'Execute shell' marked build as failure

Reply via email to