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