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/03/30 17:05:54 UTC
Build failed in Jenkins: Tajo-0.8.0-build #51
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
Jenkins build is back to normal : Tajo-0.8.0-build #52
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-0.8.0-build/52/changes>