See <https://builds.apache.org/job/Tajo-0.8.0-build/51/changes>
Changes:
[hyunsik] TAJO-706: In the case of very quick query, client can't get query
status. (hyoungjunkim via hyunsik)
------------------------------------------
[...truncated 76747 lines...]
-------------------------------------------------------------------------------
|-eb_1396191753982_0217_000005
|-eb_1396191753982_0217_000004
|-eb_1396191753982_0217_000003
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1396191753982_0217_000003 [LEAF]
=======================================================
[Outgoing]
[q_1396191753982_0217] 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_1396191753982_0217_000004 [ROOT]
=======================================================
[Incoming]
[q_1396191753982_0217] 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_1396191753982_0217_000003
=> out schema: {(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}
=> in schema: {(2) ?sum_6 (FLOAT8),?sum_7 (FLOAT8)}
=======================================================
Block Id: eb_1396191753982_0217_000005 [TERMINAL]
=======================================================
2014-03-30 15:05:51,956 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:start(101)) - AsyncDispatcher
started:q_1396191753982_0217
2014-03-30 15:05:51,956 INFO querymaster.Query (Query.java:handle(655)) -
Processing q_1396191753982_0217 of type START
2014-03-30 15:05:51,957 INFO querymaster.SubQuery
(SubQuery.java:initTaskScheduler(668)) -
org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling
2014-03-30 15:05:51,959 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:listStatus(382)) - Total input paths to process : 1
2014-03-30 15:05:51,961 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:getSplits(607)) - Total # of splits: 1
2014-03-30 15:05:51,963 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:listStatus(382)) - Total input paths to process : 1
2014-03-30 15:05:51,965 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:getSplits(607)) - Total # of splits: 1
2014-03-30 15:05:51,965 INFO querymaster.Repartitioner
(Repartitioner.java:scheduleFragmentsForJoinQuery(118)) - Left Volume: 368,
Right Volume: 604
2014-03-30 15:05:51,965 INFO querymaster.Repartitioner
(Repartitioner.java:scheduleFragmentsForJoinQuery(134)) - [Distributed Join
Strategy] : Immediate Two Way Join on Single Machine
2014-03-30 15:05:51,965 INFO querymaster.SubQuery
(SubQuery.java:transition(638)) - 2 objects are scheduled
2014-03-30 15:05:51,965 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:start(88)) - Start TaskScheduler
2014-03-30 15:05:51,965 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:calculateNumRequestContainers(98)) -
CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-03-30 15:05:51,966 INFO querymaster.SubQuery
(SubQuery.java:allocateContainers(850)) - Request Container for
eb_1396191753982_0217_000003 containers=1
2014-03-30 15:05:51,966 INFO querymaster.Query (Query.java:handle(668)) -
q_1396191753982_0217 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-03-30 15:05:51,966 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(215)) - Start TajoWorkerAllocationThread
2014-03-30 15:05:51,967 INFO querymaster.SubQuery
(SubQuery.java:transition(957)) - SubQuery (eb_1396191753982_0217_000003) has 1
containers!
2014-03-30 15:05:51,967 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(330)) - Stop TajoWorkerAllocationThread
2014-03-30 15:05:51,968 INFO worker.TaskRunner (TaskRunner.java:<init>(121)) -
Tajo Root Dir: hdfs://localhost:39881/tajo
2014-03-30 15:05:51,968 INFO worker.TaskRunner (TaskRunner.java:<init>(122)) -
Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir>
2014-03-30 15:05:51,969 INFO worker.TaskRunner (TaskRunner.java:<init>(136)) -
QueryMaster Address:asf009.sp2.ygridcore.net/67.195.138.22:41141
2014-03-30 15:05:51,969 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:run(188)) - Start
TaskRunner:eb_1396191753982_0217_000003,container_1396191753982_0217_01_000598
2014-03-30 15:05:51,970 INFO worker.TaskRunner (TaskRunner.java:init(183)) -
TaskRunner basedir is created (q_1396191753982_0217/output/3)
2014-03-30 15:05:51,970 INFO worker.TaskRunner (TaskRunner.java:run(316)) -
TaskRunner startup
2014-03-30 15:05:51,970 INFO worker.TaskRunner (TaskRunner.java:run(336)) -
Request GetTask:
eb_1396191753982_0217_000003,container_1396191753982_0217_01_000598
2014-03-30 15:05:51,971 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-30 15:05:51,974 INFO worker.TaskRunner (TaskRunner.java:run(374)) -
Accumulated Received Task: 1
2014-03-30 15:05:51,974 INFO worker.TaskRunner (TaskRunner.java:run(383)) -
Initializing: ta_1396191753982_0217_000003_000000_00
2014-03-30 15:05:51,978 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000003_000000_00 is changed to TA_PENDING
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(188)) -
==================================
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(189)) - * Subquery
ta_1396191753982_0217_000003_000000_00 is initialized
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(190)) - *
InterQuery: true, Use HASH_SHUFFLE shuffle
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(193)) - * Fragments
(num: 2)
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(194)) - * Fetches
(total:0) :
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(198)) - * Local
task dir:
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir/q_1396191753982_0217/output/3/0_0>
2014-03-30 15:05:51,978 INFO worker.Task (Task.java:<init>(203)) -
==================================
2014-03-30 15:05:51,979 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000003_000000_00 is changed to TA_RUNNING
2014-03-30 15:05:51,979 INFO planner.PhysicalPlannerImpl
(PhysicalPlannerImpl.java:checkIfInMemoryInnerJoinIsPossible(245)) -
[ta_1396191753982_0217_000003_000000_00] the volume of Left relations
(default.lineitem) is 604 B and is fit to main maemory.
2014-03-30 15:05:51,979 INFO planner.PhysicalPlannerImpl
(PhysicalPlannerImpl.java:createBestInnerJoinPlan(398)) - Join (7) chooses
[In-memory Hash Join]
2014-03-30 15:05:51,980 INFO planner.PhysicalPlannerImpl
(PhysicalPlannerImpl.java:switchJoinSidesIfNecessary(378)) -
[ta_1396191753982_0217_000003_000000_00] Right relations default.part (368 B)
is smaller than Left relations default.lineitem (604 B).
2014-03-30 15:05:51,980 INFO planner.PhysicalPlannerImpl
(PhysicalPlannerImpl.java:createInMemoryHashAggregation(898)) - The planner
chooses [Hash Aggregation]
2014-03-30 15:05:51,989 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000003_000000_00 is changed to TA_SUCCEEDED
2014-03-30 15:05:51,989 INFO worker.Task (Task.java:run(447)) - Task Counter -
total:497, succeeded: 497, killed: 0, failed: 0
2014-03-30 15:05:51,990 INFO worker.TaskRunner (TaskRunner.java:run(336)) -
Request GetTask:
eb_1396191753982_0217_000003,container_1396191753982_0217_01_000598
2014-03-30 15:05:51,990 INFO querymaster.SubQuery
(SubQuery.java:transition(1032)) - [eb_1396191753982_0217_000003] Task
Completion Event (Total: 2, Success: 2, Killed: 0, Failed: 0
2014-03-30 15:05:51,990 INFO querymaster.SubQuery
(SubQuery.java:transition(1072)) - subQuery completed -
eb_1396191753982_0217_000003 (total=2, success=2, killed=0)
2014-03-30 15:05:51,990 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped
2014-03-30 15:05:51,990 INFO worker.TaskRunner (TaskRunner.java:run(366)) -
Received ShouldDie
flag:eb_1396191753982_0217_000003,container_1396191753982_0217_01_000598
2014-03-30 15:05:51,990 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped
2014-03-30 15:05:51,991 INFO worker.TaskRunner (TaskRunner.java:stop(227)) -
Stop TaskRunner: eb_1396191753982_0217_000003
2014-03-30 15:05:51,991 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:stopTask(89)) - Stop
Task:eb_1396191753982_0217_000003,container_1396191753982_0217_01_000598
2014-03-30 15:05:51,991 INFO querymaster.Query (Query.java:handle(655)) -
Processing q_1396191753982_0217 of type SUBQUERY_COMPLETED
2014-03-30 15:05:51,991 INFO querymaster.SubQuery
(SubQuery.java:initTaskScheduler(668)) -
org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling
2014-03-30 15:05:51,991 INFO querymaster.SubQuery
(SubQuery.java:getNonLeafTaskNum(805)) - Table's volume is approximately 1 MB
2014-03-30 15:05:51,992 INFO querymaster.SubQuery
(SubQuery.java:getNonLeafTaskNum(808)) - The determined number of non-leaf
tasks is 1
2014-03-30 15:05:51,992 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:releaseWorkerResource(595)) - Release
Resource:eb_1396191753982_0217_000003,1.0,512
2014-03-30 15:05:51,992 INFO querymaster.Repartitioner
(Repartitioner.java:scheduleHashShuffledFetches(484)) -
ScheduleHashShuffledFetches - Max num=1, finalFetchURI=1
2014-03-30 15:05:51,992 INFO querymaster.Repartitioner
(Repartitioner.java:scheduleHashShuffledFetches(487)) - No Grouping Column -
determinedTaskNum is set to 1
2014-03-30 15:05:51,992 INFO querymaster.Repartitioner
(Repartitioner.java:scheduleHashShuffledFetches(494)) - DeterminedTaskNum : 1
2014-03-30 15:05:51,992 INFO querymaster.SubQuery
(SubQuery.java:transition(638)) - 1 objects are scheduled
2014-03-30 15:05:51,993 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:start(88)) - Start TaskScheduler
2014-03-30 15:05:51,993 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:calculateNumRequestContainers(98)) -
CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-03-30 15:05:51,993 INFO querymaster.SubQuery
(SubQuery.java:allocateContainers(850)) - Request Container for
eb_1396191753982_0217_000004 containers=1
2014-03-30 15:05:51,993 INFO querymaster.Query
(Query.java:executeNextBlock(576)) - Scheduling
SubQuery:eb_1396191753982_0217_000004
2014-03-30 15:05:51,993 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(215)) - Start TajoWorkerAllocationThread
2014-03-30 15:05:51,995 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(330)) - Stop TajoWorkerAllocationThread
2014-03-30 15:05:51,995 INFO querymaster.SubQuery
(SubQuery.java:transition(957)) - SubQuery (eb_1396191753982_0217_000004) has 1
containers!
2014-03-30 15:05:51,996 INFO worker.TaskRunner (TaskRunner.java:<init>(121)) -
Tajo Root Dir: hdfs://localhost:39881/tajo
2014-03-30 15:05:51,996 INFO worker.TaskRunner (TaskRunner.java:<init>(122)) -
Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir>
2014-03-30 15:05:51,996 INFO worker.TaskRunner (TaskRunner.java:<init>(136)) -
QueryMaster Address:asf009.sp2.ygridcore.net/67.195.138.22:41141
2014-03-30 15:05:51,997 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:run(188)) - Start
TaskRunner:eb_1396191753982_0217_000004,container_1396191753982_0217_01_000599
2014-03-30 15:05:51,997 INFO worker.TaskRunner (TaskRunner.java:init(183)) -
TaskRunner basedir is created (q_1396191753982_0217/output/4)
2014-03-30 15:05:51,998 INFO worker.TaskRunner (TaskRunner.java:run(316)) -
TaskRunner startup
2014-03-30 15:05:51,998 INFO worker.TaskRunner (TaskRunner.java:run(336)) -
Request GetTask:
eb_1396191753982_0217_000004,container_1396191753982_0217_01_000599
2014-03-30 15:05:52,000 INFO worker.TaskRunner (TaskRunner.java:run(374)) -
Accumulated Received Task: 1
2014-03-30 15:05:52,000 INFO worker.TaskRunner (TaskRunner.java:run(383)) -
Initializing: ta_1396191753982_0217_000004_000000_00
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(183)) - Output File
Path:
hdfs://localhost:39881/tmp/tajo-jenkins/staging/q_1396191753982_0217/RESULT/part-04-000000
2014-03-30 15:05:52,002 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000004_000000_00 is changed to TA_PENDING
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(188)) -
==================================
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(189)) - * Subquery
ta_1396191753982_0217_000004_000000_00 is initialized
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(190)) - *
InterQuery: false
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(193)) - * Fragments
(num: 1)
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(194)) - * Fetches
(total:1) :
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(196)) - Table Id:
eb_1396191753982_0217_000003, url:
http://67.195.138.22:39489/?qid=q_1396191753982_0217&sid=3&p=0&type=h&ta=0_0
2014-03-30 15:05:52,002 INFO worker.Task (Task.java:<init>(198)) - * Local
task dir:
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir/q_1396191753982_0217/output/4/0_0>
2014-03-30 15:05:52,003 INFO worker.Task (Task.java:<init>(203)) -
==================================
2014-03-30 15:05:52,005 INFO worker.Task (Task.java:init(219)) - the directory
is created
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir/q_1396191753982_0217/in/eb_1396191753982_0217_000004/0/0/eb_1396191753982_0217_000003>
2014-03-30 15:05:52,007 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000004_000000_00 is changed to TA_RUNNING
2014-03-30 15:05:52,007 INFO pullserver.TajoPullServerService
(TajoPullServerService.java:channelOpen(349)) - Current number of shuffle
connections (2)
2014-03-30 15:05:52,007 INFO worker.Fetcher (Fetcher.java:get(129)) - Fetch:
http://67.195.138.22:39489/?qid=q_1396191753982_0217&sid=3&p=0&type=h&ta=0_0
2014-03-30 15:05:52,008 INFO pullserver.TajoPullServerService
(TajoPullServerService.java:messageReceived(394)) - PullServer request param:
shuffleType=h, sid=3, partId=0, taskIds=[0_0]
2014-03-30 15:05:52,008 INFO pullserver.TajoPullServerService
(TajoPullServerService.java:messageReceived(400)) - PullServer baseDir:
file://<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-core/tajo-core-backend/target/test-data/91672f74-ad89-4da9-ab62-06116b800e57/tajo-localdir/q_1396191753982_0217/output>
2014-03-30 15:05:52,010 INFO worker.Task (Task.java:waitForFetch(356)) -
ta_1396191753982_0217_000004_000000_00 All fetches are done!
2014-03-30 15:05:52,011 INFO planner.PhysicalPlannerImpl
(PhysicalPlannerImpl.java:createInMemoryHashAggregation(898)) - The planner
chooses [Hash Aggregation]
2014-03-30 15:05:52,022 INFO BlockStateChange
(BlockManager.java:logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap
updated: 127.0.0.1:54548 is added to
blk_1073742120_1296{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1,
replicas=[ReplicaUnderConstruction[[DISK]DS-964cbb39-3ad5-40ac-8f30-5fe7354746ad:NORMAL|RBW]]}
size 0
2014-03-30 15:05:52,024 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1396191753982_0217_000004_000000_00 is changed to TA_SUCCEEDED
2014-03-30 15:05:52,025 INFO worker.Task (Task.java:run(447)) - Task Counter -
total:498, succeeded: 498, killed: 0, failed: 0
2014-03-30 15:05:52,025 INFO worker.TaskRunner (TaskRunner.java:run(336)) -
Request GetTask:
eb_1396191753982_0217_000004,container_1396191753982_0217_01_000599
2014-03-30 15:05:52,025 INFO querymaster.SubQuery
(SubQuery.java:transition(1032)) - [eb_1396191753982_0217_000004] Task
Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0
2014-03-30 15:05:52,025 INFO querymaster.SubQuery
(SubQuery.java:transition(1072)) - subQuery completed -
eb_1396191753982_0217_000004 (total=1, success=1, killed=0)
2014-03-30 15:05:52,025 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped
2014-03-30 15:05:52,025 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped
2014-03-30 15:05:52,026 INFO worker.TaskRunner (TaskRunner.java:run(366)) -
Received ShouldDie
flag:eb_1396191753982_0217_000004,container_1396191753982_0217_01_000599
2014-03-30 15:05:52,026 INFO querymaster.Query (Query.java:handle(655)) -
Processing q_1396191753982_0217 of type SUBQUERY_COMPLETED
2014-03-30 15:05:52,026 INFO worker.TaskRunner (TaskRunner.java:stop(227)) -
Stop TaskRunner: eb_1396191753982_0217_000004
2014-03-30 15:05:52,026 INFO querymaster.Query (Query.java:handle(655)) -
Processing q_1396191753982_0217 of type QUERY_COMPLETED
2014-03-30 15:05:52,026 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:stopTask(89)) - Stop
Task:eb_1396191753982_0217_000004,container_1396191753982_0217_01_000599
2014-03-30 15:05:52,026 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:releaseWorkerResource(595)) - Release
Resource:eb_1396191753982_0217_000004,1.0,512
2014-03-30 15:05:52,027 INFO querymaster.Query (Query.java:handle(668)) -
q_1396191753982_0217 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-03-30 15:05:52,027 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:handle(272)) - Query completion notified from
q_1396191753982_0217
2014-03-30 15:05:52,027 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:handle(283)) - Query final state: QUERY_SUCCEEDED
2014-03-30 15:05:52,027 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:stop(178)) - Stopping QueryMasterTask:q_1396191753982_0217
2014-03-30 15:05:52,028 INFO querymaster.QueryInProgress
(QueryInProgress.java:heartbeat(252)) - Received QueryMaster
heartbeat:q_1396191753982_0217state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=host:asf009.sp2.ygridcore.net, port=41141,41142,41140,0,
slots=m:0,d:0.0,c:0, used=m:0,d:0.0,c:0
2014-03-30 15:05:52,028 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(109)) -
=========================================================
2014-03-30 15:05:52,028 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(110)) - Stop query:q_1396191753982_0217
2014-03-30 15:05:52,028 INFO querymaster.QueryJobManager
(QueryJobManager.java:stopQuery(147)) - Stop
QueryInProgress:q_1396191753982_0217
2014-03-30 15:05:52,028 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:stopQueryMaster(634)) - release QueryMaster
resource:q_1396191753982_0217,host:asf009.sp2.ygridcore.net,
port=41141,41142,41140,39489, slots=m:1024,d:2.0,c:1, used=m:0,d:0.0,c:0
2014-03-30 15:05:52,028 WARN master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(115)) - Interrupted Exception while stopping
2014-03-30 15:05:52,028 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(118)) - q_1396191753982_0217 QueryMaster stopped
2014-03-30 15:05:52,029 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:q_1396191753982_0217
2014-03-30 15:05:52,029 WARN master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(115)) - Interrupted Exception while stopping
2014-03-30 15:05:52,029 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:QueryInProgress:q_1396191753982_0217
2014-03-30 15:05:52,029 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:stop(206)) - Stopped QueryMasterTask:q_1396191753982_0217
2014-03-30 15:05:52,359 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:closeQuery(211)) - Stop Query:q_1396191753982_0217
2014-03-30 15:05:52,360 INFO session.SessionManager
(SessionManager.java:removeSession(80)) - Session
bc863ab2-16dc-40d3-bd5e-566be7dd8a17 is removed.
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.889 sec
2014-03-30 15:05:52,364 INFO worker.TajoWorker (TajoWorker.java:run(678)) -
============================================
2014-03-30 15:05:52,364 INFO worker.TajoWorker (TajoWorker.java:run(679)) -
TajoWorker received SIGINT Signal
2014-03-30 15:05:52,365 INFO worker.TajoWorker (TajoWorker.java:run(680)) -
============================================
2014-03-30 15:05:52,365 INFO worker.TajoWorker (TajoWorker.java:run(652)) -
Worker Resource Heartbeat Thread stopped.
2014-03-30 15:05:52,385 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(126)) - Rpc (TajoWorkerProtocol) listened on
0:0:0:0:0:0:0:0:41142) shutdown
2014-03-30 15:05:52,387 INFO worker.TajoWorkerManagerService
(TajoWorkerManagerService.java:stop(95)) - TajoWorkerManagerService stopped
2014-03-30 15:05:52,390 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(126)) - Rpc (QueryMasterProtocol) listened on
0:0:0:0:0:0:0:0:41141) shutdown
2014-03-30 15:05:52,390 INFO querymaster.QueryMasterManagerService
(QueryMasterManagerService.java:stop(111)) - QueryMasterManagerService stopped
2014-03-30 15:05:52,390 INFO querymaster.QueryMaster
(QueryMaster.java:run(425)) - QueryMaster heartbeat thread stopped
2014-03-30 15:05:52,391 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:querymaster_1396191755355
2014-03-30 15:05:52,391 INFO querymaster.QueryMaster
(QueryMaster.java:stop(160)) - QueryMaster stop
2014-03-30 15:05:52,392 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:stop(107)) - TajoWorkerClientService stopping
2014-03-30 15:05:52,394 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(126)) - Rpc (QueryMasterClientProtocol) listened
on 0:0:0:0:0:0:0:0:41140) shutdown
2014-03-30 15:05:52,394 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:stop(111)) - TajoWorkerClientService stopped
2014-03-30 15:05:52,394 INFO worker.TajoWorker (TajoWorker.java:stop(347)) -
TajoWorker main thread exiting
Results :
Failed tests: testKillQuery(org.apache.tajo.client.TestTajoClient):
expected:<QUERY_KILLED> but was:<QUERY_SUCCEEDED>
Tests run: 622, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [21.114s]
[INFO] Tajo Project POM .................................. SUCCESS [1.507s]
[INFO] Tajo Common ....................................... SUCCESS [10.193s]
[INFO] Tajo Algebra ...................................... SUCCESS [2.654s]
[INFO] Tajo Rpc .......................................... SUCCESS [21.832s]
[INFO] Tajo Catalog Common ............................... SUCCESS [5.242s]
[INFO] Tajo Catalog Client ............................... SUCCESS [1.157s]
[INFO] Tajo Catalog Server ............................... SUCCESS [7.785s]
[INFO] Tajo Storage ...................................... SUCCESS [45.848s]
[INFO] Tajo Core PullServer .............................. SUCCESS [0.978s]
[INFO] Tajo Client ....................................... SUCCESS [3.785s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [0.578s]
[INFO] Tajo Core Backend ................................. FAILURE [3:42.174s]
[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:45.899s
[INFO] Finished at: Sun Mar 30 15:05:52 UTC 2014
[INFO] Final Memory: 38M/305M
[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-0.8.0-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
Updating TAJO-706
