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 2015/11/02 22:35:40 UTC
Build failed in Jenkins: Tajo-master-build #958
See <https://builds.apache.org/job/Tajo-master-build/958/>
------------------------------------------
[...truncated 752884 lines...]
2015-11-02 21:35:40,740 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(155)) - Close HashShuffleAppender:eb_1446498777614_2246_000002, intermediates=1
2015-11-02 21:35:40,740 INFO: org.apache.tajo.querymaster.Stage (finalizeShuffleReport(1306)) - eb_1446498777614_2246_000002, Finalized HASH_SHUFFLE reports: 1
2015-11-02 21:35:40,740 INFO: org.apache.tajo.querymaster.Stage (transition(1407)) - Stage completed - eb_1446498777614_2246_000002 (total=1, success=1, killed=0)
2015-11-02 21:35:40,740 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(163)) - Stopped execution block:eb_1446498777614_2246_000002
2015-11-02 21:35:40,740 INFO: org.apache.tajo.querymaster.Query (handle(868)) - Processing q_1446498777614_2246 of type STAGE_COMPLETED
2015-11-02 21:35:40,741 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1446498777614_2246_000003
2015-11-02 21:35:40,741 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(770)) - Scheduling Stage:eb_1446498777614_2246_000003
2015-11-02 21:35:40,741 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1026)) - ============>>>>> Unexpected Case! <<<<<================
2015-11-02 21:35:40,741 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1030)) - eb_1446498777614_2246_000003, Table's volume is approximately 1 MB
2015-11-02 21:35:40,741 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1033)) - eb_1446498777614_2246_000003, The determined number of partitions is 1
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(901)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1446498777614_2246_000003
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleFragmentsForJoinQuery(262)) - [Distributed Join Strategy] : Symmetric Repartition Join
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(358)) - Larger intermediate data is approximately 1 MB
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(361)) - The calculated number of tasks is 1
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(362)) - The number of total shuffle keys is 1
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(366)) - The determined number of join tasks is 1
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.Stage (run(853)) - 1 objects are scheduled
2015-11-02 21:35:40,761 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(134)) - Start TaskScheduler
2015-11-02 21:35:40,763 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(114)) - QueryMaster Address:asf906.gq1.ygridcore.net:22654
2015-11-02 21:35:40,765 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:44362/tajo
2015-11-02 21:35:40,765 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir>
2015-11-02 21:35:40,766 INFO: org.apache.tajo.worker.TaskManager (handle(184)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (<init>(116)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/3)>
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (init(197)) - Initializing: ta_1446498777614_2246_000003_000000_00
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - ==================================
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (initPlan(153)) - * Stage ta_1446498777614_2246_000003_000000_00 is initialized
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (initPlan(154)) - * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 4), Fetches (total:2) :
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (initPlan(164)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/3/0_0>
2015-11-02 21:35:40,767 INFO: org.apache.tajo.worker.TaskImpl (initPlan(169)) - ==================================
2015-11-02 21:35:40,768 INFO: org.apache.tajo.worker.TaskImpl (init(216)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/in/eb_1446498777614_2246_000003/0/0/eb_1446498777614_2246_000001>
2015-11-02 21:35:40,768 INFO: org.apache.tajo.worker.TaskImpl (init(216)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/in/eb_1446498777614_2246_000003/0/0/eb_1446498777614_2246_000002>
2015-11-02 21:35:40,770 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(725)) - Create shuffle Fetchers local:2, remote:0
2015-11-02 21:35:40,770 INFO: org.apache.tajo.worker.TaskImpl (run(617)) - Add a new FileChunk to local chunk list
2015-11-02 21:35:40,770 INFO: org.apache.tajo.worker.TaskImpl (run(617)) - Add a new FileChunk to local chunk list
2015-11-02 21:35:40,770 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(364)) - ta_1446498777614_2246_000003_000000_00 All fetches are done!
2015-11-02 21:35:40,771 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createFullOuterHashJoinPlan(622)) - Full Outer Join (6) chooses [Hash Join]
2015-11-02 21:35:40,772 INFO: org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(80)) - Output data directory: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/3/0_0/output>
2015-11-02 21:35:40,790 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(365)) - Saving query summary: hdfs://localhost:44362/tmp/tajo-jenkins/staging/history/20151102/query-detail/q_1446498777614_2245/query.hist
2015-11-02 21:35:40,810 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1446498777614_2246_000003_000000_00] Chunks creation time: 0 msec
2015-11-02 21:35:40,810 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50663 is added to blk_1073748814_7990{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-54fb4f5c-5bc3-4346-9624-3a7341dc7f6a:NORMAL:127.0.0.1:50663|RBW]]} size 0
2015-11-02 21:35:40,812 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:44362/tmp/tajo-jenkins/staging/history/20151102/query-detail/q_1446498777614_2245/eb_1446498777614_2245_000001.hist
2015-11-02 21:35:40,816 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50663 is added to blk_1073748815_7991{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-ff6de253-a975-4c3c-8aed-b708a08a730d:NORMAL:127.0.0.1:50663|RBW]]} size 0
2015-11-02 21:35:40,817 INFO: org.apache.tajo.worker.TaskImpl (run(462)) - ta_1446498777614_2246_000003_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-11-02 21:35:40,817 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:44362/tmp/tajo-jenkins/staging/history/20151102/query-detail/q_1446498777614_2245/eb_1446498777614_2245_000002.hist
2015-11-02 21:35:40,817 INFO: org.apache.tajo.querymaster.Stage (transition(1349)) - Stage - eb_1446498777614_2246_000003 finalize RANGE_SHUFFLE (total=1, success=1, killed=0)
2015-11-02 21:35:40,818 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(163)) - Task Scheduler stopped
2015-11-02 21:35:40,818 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(126)) - TaskScheduler schedulingThread stopped
2015-11-02 21:35:40,818 INFO: org.apache.tajo.querymaster.Stage (transition(1407)) - Stage completed - eb_1446498777614_2246_000003 (total=1, success=1, killed=0)
2015-11-02 21:35:40,818 INFO: org.apache.tajo.querymaster.Query (handle(868)) - Processing q_1446498777614_2246 of type STAGE_COMPLETED
2015-11-02 21:35:40,818 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1446498777614_2246_000004
2015-11-02 21:35:40,818 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(770)) - Scheduling Stage:eb_1446498777614_2246_000004
2015-11-02 21:35:40,819 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(163)) - Stopped execution block:eb_1446498777614_2246_000003
2015-11-02 21:35:40,820 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50663 is added to blk_1073748816_7992{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-54fb4f5c-5bc3-4346-9624-3a7341dc7f6a:NORMAL:127.0.0.1:50663|RBW]]} size 0
2015-11-02 21:35:40,836 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(901)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1446498777614_2246_000004
2015-11-02 21:35:40,836 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1095)) - eb_1446498777614_2246_000004, Table's volume is approximately 1 MB
2015-11-02 21:35:40,836 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1100)) - eb_1446498777614_2246_000004, The determined number of non-leaf tasks is 1
2015-11-02 21:35:40,837 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleRangeShuffledFetches(673)) - eb_1446498777614_2246_000004, Try to divide [(1,1), (5,3)) into 1 sub ranges (total units: 1)
2015-11-02 21:35:40,837 INFO: org.apache.tajo.engine.utils.TupleUtil (setMaxRangeIfNull(104)) - Set null into range: default.orders.o_orderkey, current tuple is (5,NULL)
2015-11-02 21:35:40,837 INFO: org.apache.tajo.querymaster.Stage (run(853)) - 1 objects are scheduled
2015-11-02 21:35:40,837 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(134)) - Start TaskScheduler
2015-11-02 21:35:40,839 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(114)) - QueryMaster Address:asf906.gq1.ygridcore.net:22654
2015-11-02 21:35:40,841 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:44362/tajo
2015-11-02 21:35:40,841 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir>
2015-11-02 21:35:40,842 INFO: org.apache.tajo.worker.TaskManager (handle(184)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-11-02 21:35:40,842 INFO: org.apache.tajo.worker.TaskImpl (<init>(116)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/4)>
2015-11-02 21:35:40,842 INFO: org.apache.tajo.worker.TaskImpl (init(197)) - Initializing: ta_1446498777614_2246_000004_000000_00
2015-11-02 21:35:40,842 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(289)) - Output File Path: hdfs://localhost:44362/tmp/tajo-jenkins/staging/q_1446498777614_2246/RESULT/part-04-000000-000
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(147)) - Output File Path: hdfs://localhost:44362/tmp/tajo-jenkins/staging/q_1446498777614_2246/RESULT/part-04-000000-000
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - ==================================
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(153)) - * Stage ta_1446498777614_2246_000004_000000_00 is initialized
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(154)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) :
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(164)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/4/0_0>
2015-11-02 21:35:40,843 INFO: org.apache.tajo.worker.TaskImpl (initPlan(169)) - ==================================
2015-11-02 21:35:40,844 INFO: org.apache.tajo.worker.TaskImpl (init(216)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/in/eb_1446498777614_2246_000004/0/0/eb_1446498777614_2246_000003>
2015-11-02 21:35:40,865 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(688)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/3/0_0/output/output> (start=(1,1), end=(5,NULL), last=true)
2015-11-02 21:35:40,865 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(725)) - Create shuffle Fetchers local:1, remote:0
2015-11-02 21:35:40,865 INFO: org.apache.tajo.worker.TaskImpl (run(617)) - Add a new FileChunk to local chunk list
2015-11-02 21:35:40,866 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(364)) - ta_1446498777614_2246_000004_000000_00 All fetches are done!
2015-11-02 21:35:40,868 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1446498777614_2246_000004_000000_00] Total merge time: 0 msec
2015-11-02 21:35:40,868 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (close(791)) - Delete file: "fragment": {"id": "eb_1446498777614_2246_000003", "path": <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/tajo-localdir/q_1446498777614_2246/output/3/0_0/output/output",> "start": 0,"length": 49}
2015-11-02 21:35:40,871 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50663 is added to blk_1073748817_7993{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-ff6de253-a975-4c3c-8aed-b708a08a730d:NORMAL:127.0.0.1:50663|FINALIZED]]} size 0
2015-11-02 21:35:40,872 INFO: org.apache.tajo.worker.TaskImpl (run(462)) - ta_1446498777614_2246_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-11-02 21:35:40,872 INFO: org.apache.tajo.querymaster.Stage (transition(1349)) - Stage - eb_1446498777614_2246_000004 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-11-02 21:35:40,872 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(163)) - Task Scheduler stopped
2015-11-02 21:35:40,872 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(126)) - TaskScheduler schedulingThread stopped
2015-11-02 21:35:40,873 INFO: org.apache.tajo.querymaster.Stage (transition(1407)) - Stage completed - eb_1446498777614_2246_000004 (total=1, success=1, killed=0)
2015-11-02 21:35:40,873 INFO: org.apache.tajo.querymaster.Query (handle(868)) - Processing q_1446498777614_2246 of type STAGE_COMPLETED
2015-11-02 21:35:40,873 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1446498777614_2246_000005
2015-11-02 21:35:40,873 INFO: org.apache.tajo.querymaster.Query (transition(815)) - Complete Stage[eb_1446498777614_2246_000004], State: SUCCEEDED, 4/4.
2015-11-02 21:35:40,873 INFO: org.apache.tajo.querymaster.Query (handle(868)) - Processing q_1446498777614_2246 of type QUERY_COMPLETED
2015-11-02 21:35:40,874 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(163)) - Stopped execution block:eb_1446498777614_2246_000004
2015-11-02 21:35:40,874 INFO: org.apache.tajo.querymaster.Query (handle(886)) - q_1446498777614_2246 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-11-02 21:35:40,874 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(296)) - Query completion notified from q_1446498777614_2246 final state: QUERY_SUCCEEDED
2015-11-02 21:35:40,875 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(259)) - Received QueryMaster heartbeat:q_1446498777614_2246,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf906.gq1.ygridcore.net
2015-11-02 21:35:40,875 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1446498777614_2246
2015-11-02 21:35:40,875 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(124)) - =========================================================
2015-11-02 21:35:40,875 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(125)) - Stop query:q_1446498777614_2246
2015-11-02 21:35:40,875 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(172)) - Stopping QueryMasterTask:q_1446498777614_2246
2015-11-02 21:35:40,875 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(473)) - Cleanup resources of all workers. Query: q_1446498777614_2246, workers: 1
2015-11-02 21:35:40,875 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(188)) - Stopped QueryMasterTask:q_1446498777614_2246
2015-11-02 21:35:40,893 INFO: org.apache.tajo.storage.FileTablespace (listStatus(363)) - Total input paths to process : 1
2015-11-02 21:35:40,894 INFO: org.apache.tajo.storage.FileTablespace (getSplits(564)) - Total # of splits: 1
2015-11-02 21:35:40,897 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073748817_7993 127.0.0.1:50663
2015-11-02 21:35:40,898 INFO: org.apache.tajo.master.exec.NonForwardQueryResultFileScanner (close(175)) - "Sent result to client for 6eee591e-03ae-4df1-80a4-b46a7aa9e197, queryId: q_1446498777614_2246 rows: 5
2015-11-02 21:35:40,900 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 6eee591e-03ae-4df1-80a4-b46a7aa9e197 is removed.
2015-11-02 21:35:40,904 INFO: org.apache.tajo.session.SessionManager (createSession(79)) - Session a9a5d3f0-cac8-46d3-9b12-0cabcd3ed9fe is created.
2015-11-02 21:35:40,906 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: create table "TEST_DESC_TABLE" (col1 int4, col2 int4)
2015-11-02 21:35:40,907 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-11-02 21:35:40,907 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-11-02 21:35:40,908 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2015-11-02 21:35:40,908 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-11-02 21:35:40,911 INFO: org.apache.tajo.catalog.CatalogServer (createTable(691)) - relation "default.TEST_DESC_TABLE" is added to the catalog (127.0.0.1:22648)
2015-11-02 21:35:40,911 INFO: org.apache.tajo.master.exec.DDLExecutor (create(112)) - relation 'default.TEST_DESC_TABLE' created.
2015-11-02 21:35:40,915 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session a9a5d3f0-cac8-46d3-9b12-0cabcd3ed9fe is removed.
Tests run: 23, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.237 sec - in org.apache.tajo.cli.tsql.TestTajoCli
2015-11-02 21:35:40,923 INFO: org.mortbay.log (invoke0(?)) - Shutdown hook executing
2015-11-02 21:35:40,923 INFO: org.mortbay.log (invoke(?)) - Shutdown hook complete
Nov 2, 2015 9:23:24 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:24 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:40 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:40 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:40 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:40 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:40 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Nov 2, 2015 9:23:43 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
2015-11-02 21:35:40,928 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 1a00f897-b4c0-4adb-8491-f55a496a4573 is removed.
2015-11-02 21:35:40,930 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 4e5e9681-d849-42c1-aec8-f5799b777072 is removed.
2015-11-02 21:35:40,932 INFO: org.apache.tajo.worker.TajoWorker (run(564)) - ============================================
2015-11-02 21:35:40,932 INFO: org.apache.tajo.worker.TajoWorker (run(565)) - TajoWorker received SIGINT Signal
2015-11-02 21:35:40,932 INFO: org.apache.tajo.worker.TajoWorker (run(566)) - ============================================
2015-11-02 21:35:40,935 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf906.gq1.ygridcore.net_22652 stopped.
2015-11-02 21:35:40,937 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-11-02 21:35:40,974 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(115)) - NodeStatusUpdater stopped.
2015-11-02 21:35:40,974 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(265)) - Heartbeat Thread stopped.
2015-11-02 21:35:40,977 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:22654) shutdown
2015-11-02 21:35:40,979 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-11-02 21:35:40,979 INFO: org.apache.tajo.querymaster.QueryMaster (run(427)) - QueryMaster heartbeat thread stopped
2015-11-02 21:35:40,979 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(162)) - QueryMaster stopped
2015-11-02 21:35:40,979 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2015-11-02 21:35:40,980 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:22653) shutdown
2015-11-02 21:35:40,980 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2015-11-02 21:35:40,980 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:22652) shutdown
2015-11-02 21:35:40,980 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-11-02 21:35:40,981 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(374)) - TajoWorker main thread exiting
2015-11-02 21:35:42,583 INFO: org.apache.tajo.rpc.NettyClientBase (userEventTriggered(420)) - Idle connection closed successfully :[id: 0x4462f77b, /127.0.0.1:44512 :> /127.0.0.1:22649]
2015-11-02 21:35:42,887 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:50663 to delete [blk_1073748817_7993, blk_1073748813_7989]
2015-11-02 21:35:45,392 INFO: org.apache.tajo.master.TajoMaster (run(577)) - ============================================
2015-11-02 21:35:45,392 INFO: org.apache.tajo.master.TajoMaster (run(578)) - TajoMaster received SIGINT Signal
2015-11-02 21:35:45,392 INFO: org.apache.tajo.master.TajoMaster (run(579)) - ============================================
2015-11-02 21:35:45,394 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (Tajo-REST) listened on 0:0:0:0:0:0:0:0:22651) shutdown
2015-11-02 21:35:45,394 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2015-11-02 21:35:45,397 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_22650 stopped.
2015-11-02 21:35:45,401 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50663 is added to blk_1073741834_1010{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-54fb4f5c-5bc3-4346-9624-3a7341dc7f6a:NORMAL:127.0.0.1:50663|RBW]]} size 524
2015-11-02 21:35:45,401 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:22650) shutdown
2015-11-02 21:35:45,401 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-11-02 21:35:45,401 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:22649) shutdown
2015-11-02 21:35:45,403 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(185)) - Catalog Server (127.0.0.1:22648) shutdown
2015-11-02 21:35:45,404 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (CatalogProtocol) listened on 127.0.0.1:22648) shutdown
2015-11-02 21:35:45,404 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2979)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/a39e5c5a-fd47-4753-bc69-17eec193ecb5/db;create=true)>
2015-11-02 21:35:45,406 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:22647) shutdown
2015-11-02 21:35:45,406 INFO: org.apache.tajo.master.TajoMaster (serviceStop(437)) - Tajo Master main thread exiting
2015-11-02 21:35:45,651 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(68)) - Derby shutdown complete normally.
2015-11-02 21:35:45,651 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(75)) - Shutdown database
Results :
Tests in error:
TestKillQuery.testKillQueryFromInitState:135 ยป IO QUERY_ERROR
Tests run: 1713, Failures: 0, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.515 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.601 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 5.232 s]
[INFO] Tajo Common ....................................... SUCCESS [ 31.116 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.469 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.091 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 7.428 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.245 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 49.680 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.546 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 11.415 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 2.702 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 49.646 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.094 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.754 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.736 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 3.632 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.055 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.910 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.388 s]
[INFO] Tajo Core ......................................... SUCCESS [ 7.483 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.926 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 9.565 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.056 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.954 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.037 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.505 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.453 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 33.451 s]
[INFO] Tajo JDBC storage common .......................... SUCCESS [ 0.847 s]
[INFO] Tajo PostgreSQL JDBC storage ...................... SUCCESS [ 0.900 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.969 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.484 s]
[INFO] Tajo Core Tests ................................... FAILURE [23:00 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 27:16 min
[INFO] Finished at: 2015-11-02T21:35:46+00:00
[INFO] Final Memory: 161M/2322M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/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-tests
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Tajo-master-build #959
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/959/changes>