See <https://builds.apache.org/job/Tajo-master-build/574/changes>
Changes: [jihun] TAJO-1317: Parallel Test Executions on Tajo Core Project ------------------------------------------ [...truncated 377931 lines...] 2015-02-02 13:02:39,009 INFO: org.apache.tajo.worker.Task (getFetchRunners(686)) - Try to get local file chunk at local host 2015-02-02 13:02:39,009 INFO: org.apache.tajo.worker.Task (getLocalStoredFileChunk(728)) - getLocalStoredFileChunk starts 2015-02-02 13:02:39,009 INFO: org.apache.tajo.worker.Task (getLocalStoredFileChunk(763)) - PullServer request param: shuffleType=h, sid=1, partId=0, taskIds=null 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.Task (getFetchRunners(714)) - Create a new Fetcher with storeChunk: (start=0, length=30, fromRemote=false, ebId=eb_1422881309262_0891_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/1/hash-shuffle/0/0> 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.Fetcher (get(123)) - Get pseudo fetch from local host 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.Task (run(608)) - Add a new FileChunk to local chunk list 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.Fetcher (get(123)) - Get pseudo fetch from local host 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.Task (run(608)) - Add a new FileChunk to local chunk list 2015-02-02 13:02:39,010 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1422881309262_0891_000003_000000_00 is changed to TA_RUNNING 2015-02-02 13:02:39,011 INFO: org.apache.tajo.worker.Task (waitForFetch(360)) - ta_1422881309262_0891_000003_000000_00 All fetches are done! 2015-02-02 13:02:39,011 INFO: org.apache.tajo.worker.Task (localizeFetchedData(564)) - One local chunk is added to listTablets 2015-02-02 13:02:39,011 INFO: org.apache.tajo.worker.Task (localizeFetchedData(564)) - One local chunk is added to listTablets 2015-02-02 13:02:39,012 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createFullOuterHashJoinPlan(617)) - Full Outer Join (6) chooses [Hash Join] 2015-02-02 13:02:39,013 INFO: org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(76)) - Output data directory: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/3/0_0/output> 2015-02-02 13:02:39,033 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1422881309262_0891_000003_000000_00] Chunks creation time: 0 msec 2015-02-02 13:02:39,039 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1422881309262_0891_000003_000000_00 is changed to TA_SUCCEEDED 2015-02-02 13:02:39,039 INFO: org.apache.tajo.worker.Task (run(455)) - ta_1422881309262_0891_000003_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0 2015-02-02 13:02:39,040 INFO: org.apache.tajo.worker.TaskRunner (run(211)) - Request GetTask: eb_1422881309262_0891_000003,container_1422881309262_0891_01_003290 2015-02-02 13:02:39,040 INFO: org.apache.tajo.querymaster.Stage (transition(1337)) - Stage finalize - eb_1422881309262_0891_000003 (total=1, success=1, killed=0) 2015-02-02 13:02:39,040 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(109)) - TaskScheduler schedulingThread stopped 2015-02-02 13:02:39,040 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-02-02 13:02:39,041 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(181)) - cleanup executionBlocks: eb_1422881309262_0891_000001,eb_1422881309262_0891_000002 2015-02-02 13:02:39,041 INFO: org.apache.tajo.worker.TaskRunner (run(249)) - Received ShouldDie flag:eb_1422881309262_0891_000003,container_1422881309262_0891_01_003290 2015-02-02 13:02:39,041 INFO: org.apache.tajo.worker.TaskRunner (stop(151)) - Stop TaskRunner: eb_1422881309262_0891_000003,container_1422881309262_0891_01_003290 2015-02-02 13:02:39,041 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTaskRunner(116)) - Stop Task:eb_1422881309262_0891_000003,container_1422881309262_0891_01_003290 2015-02-02 13:02:39,042 INFO: org.apache.tajo.querymaster.Stage (transition(1343)) - eb_1422881309262_0891_000003, waiting for shuffle reports. expected Tasks:1 2015-02-02 13:02:39,042 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.5,512 2015-02-02 13:02:39,043 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(165)) - ======================== Processing eb_1422881309262_0891_000003 of type STOP 2015-02-02 13:02:39,043 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1422881309262_0891_000003, not a hash shuffle 2015-02-02 13:02:39,043 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1422881309262_0891_000003, not a hash shuffle 2015-02-02 13:02:39,043 INFO: org.apache.tajo.querymaster.Stage (transition(1323)) - eb_1422881309262_0891_000003, Finalized shuffle reports: 1 2015-02-02 13:02:39,043 INFO: org.apache.tajo.querymaster.Stage (transition(1387)) - Stage completed - eb_1422881309262_0891_000003 (total=1, success=1, killed=0) 2015-02-02 13:02:39,043 INFO: org.apache.tajo.querymaster.Query (handle(712)) - Processing q_1422881309262_0891 of type STAGE_COMPLETED 2015-02-02 13:02:39,044 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(203)) - Stopped execution block:eb_1422881309262_0891_000003 2015-02-02 13:02:39,044 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(846)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1422881309262_0891_000004 2015-02-02 13:02:39,044 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(632)) - Scheduling Stage:eb_1422881309262_0891_000004 2015-02-02 13:02:39,044 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1008)) - eb_1422881309262_0891_000004, Table's volume is approximately 1 MB 2015-02-02 13:02:39,044 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1011)) - eb_1422881309262_0891_000004, The determined number of non-leaf tasks is 1 2015-02-02 13:02:39,045 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleRangeShuffledFetches(696)) - eb_1422881309262_0891_000004, Try to divide [(0=>1, 1=>1), (0=>5, 1=>3)) into 1 sub ranges (total units: 1) 2015-02-02 13:02:39,045 INFO: org.apache.tajo.engine.utils.TupleUtil (setMaxRangeIfNull(111)) - Set null into range: default.orders.o_orderkey, current tuple is (0=>5, 1=>NULL) 2015-02-02 13:02:39,046 INFO: org.apache.tajo.querymaster.Stage (run(798)) - 1 objects are scheduled 2015-02-02 13:02:39,047 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(91)) - Start TaskScheduler 2015-02-02 13:02:39,047 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(102)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1 2015-02-02 13:02:39,047 INFO: org.apache.tajo.querymaster.Stage (allocateContainers(1059)) - Request Container for eb_1422881309262_0891_000004 containers=1 2015-02-02 13:02:39,047 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(256)) - Start TajoWorkerAllocationThread 2015-02-02 13:02:39,049 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(369)) - Stop TajoWorkerAllocationThread 2015-02-02 13:02:39,049 INFO: org.apache.tajo.querymaster.Stage (transition(1170)) - Stage (eb_1422881309262_0891_000004) has 1 containers! 2015-02-02 13:02:39,050 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(165)) - ======================== Processing eb_1422881309262_0891_000004 of type START 2015-02-02 13:02:39,050 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(122)) - Tajo Root Dir: hdfs://localhost:54973/tajo 2015-02-02 13:02:39,050 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(123)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir> 2015-02-02 13:02:39,051 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(126)) - QueryMaster Address:asf906.gq1.ygridcore.net/67.195.81.150:25889 2015-02-02 13:02:39,052 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(181)) - Start TaskRunner:eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,052 INFO: org.apache.tajo.worker.TaskRunner (init(121)) - TaskRunner basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/4)> 2015-02-02 13:02:39,052 INFO: org.apache.tajo.worker.TaskRunner (run(180)) - TaskRunner startup 2015-02-02 13:02:39,052 INFO: org.apache.tajo.worker.TaskRunner (run(211)) - Request GetTask: eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,054 INFO: org.apache.tajo.worker.TaskRunner (run(255)) - Accumulated Received Task: 1 2015-02-02 13:02:39,054 INFO: org.apache.tajo.worker.TaskRunner (run(264)) - Initializing: ta_1422881309262_0891_000004_000000_00 2015-02-02 13:02:39,055 INFO: org.apache.tajo.storage.FileStorageManager (getAppenderFilePath(283)) - Output File Path: hdfs://localhost:54973/tmp/tajo-jenkins/staging/q_1422881309262_0891/RESULT/part-04-000000-000 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(155)) - Output File Path: hdfs://localhost:54973/tmp/tajo-jenkins/staging/q_1422881309262_0891/RESULT/part-04-000000-000 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1422881309262_0891_000004_000000_00 is changed to TA_PENDING 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(162)) - ================================== 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(163)) - * Stage ta_1422881309262_0891_000004_000000_00 is initialized 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(164)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) : 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(174)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/4/0_0> 2015-02-02 13:02:39,055 INFO: org.apache.tajo.worker.Task (<init>(179)) - ================================== 2015-02-02 13:02:39,057 INFO: org.apache.tajo.worker.Task (init(197)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/in/eb_1422881309262_0891_000004/0/0/eb_1422881309262_0891_000003> 2015-02-02 13:02:39,059 INFO: org.apache.tajo.worker.Task (getFetchRunners(686)) - Try to get local file chunk at local host 2015-02-02 13:02:39,059 INFO: org.apache.tajo.worker.Task (getLocalStoredFileChunk(728)) - getLocalStoredFileChunk starts 2015-02-02 13:02:39,059 INFO: org.apache.tajo.worker.Task (getLocalStoredFileChunk(763)) - PullServer request param: shuffleType=r, sid=3, partId=0, taskIds=[0_0] 2015-02-02 13:02:39,075 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileCunks(712)) - BSTIndex is loaded from disk ((0=>1, 1=>1), (0=>5, 1=>NULL) 2015-02-02 13:02:39,075 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileCunks(736)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/3/0_0/output/output> (start=(0=>1, 1=>1), end=(0=>5, 1=>NULL), last=true) 2015-02-02 13:02:39,075 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileCunks(805)) - Retrieve File Chunk: (start=0, length=49, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/3/0_0/output/output> 2015-02-02 13:02:39,075 INFO: org.apache.tajo.worker.Task (getFetchRunners(714)) - Create a new Fetcher with storeChunk: (start=0, length=49, fromRemote=false, ebId=eb_1422881309262_0891_000003) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/3/0_0/output/output> 2015-02-02 13:02:39,076 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1422881309262_0891_000004_000000_00 is changed to TA_RUNNING 2015-02-02 13:02:39,076 INFO: org.apache.tajo.worker.Fetcher (get(123)) - Get pseudo fetch from local host 2015-02-02 13:02:39,076 INFO: org.apache.tajo.worker.Task (run(608)) - Add a new FileChunk to local chunk list 2015-02-02 13:02:39,076 INFO: org.apache.tajo.worker.Task (waitForFetch(360)) - ta_1422881309262_0891_000004_000000_00 All fetches are done! 2015-02-02 13:02:39,076 INFO: org.apache.tajo.worker.Task (localizeFetchedData(564)) - One local chunk is added to listTablets 2015-02-02 13:02:39,080 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1422881309262_0891_000004_000000_00] Total merge time: 0 msec 2015-02-02 13:02:39,081 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (close(860)) - Delete file: "fragment": {"id": "eb_1422881309262_0891_000003", "path": <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3906b2c2-686e-4982-9ecf-bfb9b4fa2c50/tajo-localdir/q_1422881309262_0891/output/3/0_0/output/output";,> "start": 0,"length": 49} 2015-02-02 13:02:39,086 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746815_5991{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-2875e955-213b-4f22-84ef-b335dcca3d84:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,087 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(145)) - Query status of ta_1422881309262_0891_000004_000000_00 is changed to TA_SUCCEEDED 2015-02-02 13:02:39,087 INFO: org.apache.tajo.worker.Task (run(455)) - ta_1422881309262_0891_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0 2015-02-02 13:02:39,088 INFO: org.apache.tajo.worker.TaskRunner (run(211)) - Request GetTask: eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,088 INFO: org.apache.tajo.querymaster.Stage (transition(1337)) - Stage finalize - eb_1422881309262_0891_000004 (total=1, success=1, killed=0) 2015-02-02 13:02:39,088 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(109)) - TaskScheduler schedulingThread stopped 2015-02-02 13:02:39,088 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(152)) - Task Scheduler stopped 2015-02-02 13:02:39,088 INFO: org.apache.tajo.worker.TaskRunner (run(249)) - Received ShouldDie flag:eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,088 INFO: org.apache.tajo.querymaster.QueryMaster (cleanupExecutionBlock(181)) - cleanup executionBlocks: eb_1422881309262_0891_000003 2015-02-02 13:02:39,089 INFO: org.apache.tajo.worker.TaskRunner (stop(151)) - Stop TaskRunner: eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,089 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTaskRunner(116)) - Stop Task:eb_1422881309262_0891_000004,container_1422881309262_0891_01_003291 2015-02-02 13:02:39,090 INFO: org.apache.tajo.querymaster.Stage (transition(1343)) - eb_1422881309262_0891_000004, waiting for shuffle reports. expected Tasks:1 2015-02-02 13:02:39,090 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.5,512 2015-02-02 13:02:39,091 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(165)) - ======================== Processing eb_1422881309262_0891_000004 of type STOP 2015-02-02 13:02:39,091 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1422881309262_0891_000004, not a hash shuffle 2015-02-02 13:02:39,091 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(132)) - Close HashShuffleAppender:eb_1422881309262_0891_000004, not a hash shuffle 2015-02-02 13:02:39,091 INFO: org.apache.tajo.querymaster.Stage (transition(1323)) - eb_1422881309262_0891_000004, Finalized shuffle reports: 1 2015-02-02 13:02:39,091 INFO: org.apache.tajo.worker.TaskRunnerManager (handle(203)) - Stopped execution block:eb_1422881309262_0891_000004 2015-02-02 13:02:39,092 INFO: org.apache.tajo.querymaster.Stage (transition(1387)) - Stage completed - eb_1422881309262_0891_000004 (total=1, success=1, killed=0) 2015-02-02 13:02:39,092 INFO: org.apache.tajo.querymaster.Query (handle(712)) - Processing q_1422881309262_0891 of type STAGE_COMPLETED 2015-02-02 13:02:39,092 INFO: org.apache.tajo.querymaster.Query (handle(712)) - Processing q_1422881309262_0891 of type QUERY_COMPLETED 2015-02-02 13:02:39,093 INFO: org.apache.tajo.querymaster.Query (handle(730)) - q_1422881309262_0891 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED 2015-02-02 13:02:39,093 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(276)) - Query completion notified from q_1422881309262_0891 2015-02-02 13:02:39,093 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(287)) - Query final state: QUERY_SUCCEEDED 2015-02-02 13:02:39,093 INFO: org.apache.tajo.querymaster.QueryMasterTask (stop(183)) - Stopping QueryMasterTask:q_1422881309262_0891 2015-02-02 13:02:39,094 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(196)) - Received QueryMaster heartbeat:q_1422881309262_0891,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf906.gq1.ygridcore.net 2015-02-02 13:02:39,094 INFO: org.apache.tajo.querymaster.QueryMasterTask (stop(196)) - Stopped QueryMasterTask:q_1422881309262_0891 2015-02-02 13:02:39,094 INFO: org.apache.tajo.master.QueryManager (stopQuery(238)) - Stop QueryInProgress:q_1422881309262_0891 2015-02-02 13:02:39,095 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(97)) - ========================================================= 2015-02-02 13:02:39,094 INFO: org.apache.tajo.querymaster.QueryMaster (cleanup(205)) - cleanup query resources : q_1422881309262_0891 2015-02-02 13:02:39,095 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(98)) - Stop query:q_1422881309262_0891 2015-02-02 13:02:39,095 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(513)) - Release Resource: 0.0,512 2015-02-02 13:02:39,095 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseQueryMaster(535)) - Released QueryMaster (q_1422881309262_0891) resource. 2015-02-02 13:02:39,098 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(359)) - Saving query summary: hdfs://localhost:54973/tmp/tajo-jenkins/staging/history/20150202/query-detail/q_1422881309262_0891/query.hist 2015-02-02 13:02:39,105 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746816_5992{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-4c66cdec-78b8-4040-a4fd-18007c25f3d2:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,107 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(373)) - Saving query unit: hdfs://localhost:54973/tmp/tajo-jenkins/staging/history/20150202/query-detail/q_1422881309262_0891/eb_1422881309262_0891_000004.hist 2015-02-02 13:02:39,111 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746817_5993{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-2875e955-213b-4f22-84ef-b335dcca3d84:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,114 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(373)) - Saving query unit: hdfs://localhost:54973/tmp/tajo-jenkins/staging/history/20150202/query-detail/q_1422881309262_0891/eb_1422881309262_0891_000001.hist 2015-02-02 13:02:39,115 INFO: org.apache.tajo.session.SessionManager (removeSession(79)) - Session ae3149c3-4ef7-4277-96db-b2e50fe13034 is removed. 2015-02-02 13:02:39,118 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746818_5994{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-4c66cdec-78b8-4040-a4fd-18007c25f3d2:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,120 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(373)) - Saving query unit: hdfs://localhost:54973/tmp/tajo-jenkins/staging/history/20150202/query-detail/q_1422881309262_0891/eb_1422881309262_0891_000002.hist 2015-02-02 13:02:39,122 INFO: org.apache.tajo.session.SessionManager (createSession(73)) - Session c9f9c121-c13a-4ac4-ac4a-980af2beeee7 is created. 2015-02-02 13:02:39,124 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746819_5995{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-2875e955-213b-4f22-84ef-b335dcca3d84:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,125 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(150)) - Query: create table "TEST_DESC_TABLE" (col1 int4, col2 int4) 2015-02-02 13:02:39,129 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(239)) - Non Optimized Query: ----------------------------- Query Block Graph ----------------------------- |-#ROOT ----------------------------- Optimization Log: ----------------------------- 2015-02-02 13:02:39,129 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(241)) - ============================================= 2015-02-02 13:02:39,129 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(373)) - Saving query unit: hdfs://localhost:54973/tmp/tajo-jenkins/staging/history/20150202/query-detail/q_1422881309262_0891/eb_1422881309262_0891_000003.hist 2015-02-02 13:02:39,129 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(242)) - Optimized Query: ----------------------------- Query Block Graph ----------------------------- |-#ROOT ----------------------------- Optimization Log: ----------------------------- 2015-02-02 13:02:39,130 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(243)) - ============================================= 2015-02-02 13:02:39,133 INFO: org.apache.tajo.catalog.CatalogServer (createTable(605)) - relation "default.TEST_DESC_TABLE" is added to the catalog (127.0.0.1:25884) 2015-02-02 13:02:39,133 INFO: org.apache.tajo.master.exec.DDLExecutor (createTable(249)) - Table default.TEST_DESC_TABLE is created (0) 2015-02-02 13:02:39,133 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073746820_5996{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-4c66cdec-78b8-4040-a4fd-18007c25f3d2:NORMAL|RBW]]} size 0 2015-02-02 13:02:39,139 INFO: org.apache.tajo.session.SessionManager (removeSession(79)) - Session c9f9c121-c13a-4ac4-ac4a-980af2beeee7 is removed. Tests run: 15, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.519 sec - in org.apache.tajo.cli.tsql.TestTajoCli 2015-02-02 13:02:39,146 INFO: org.apache.tajo.master.TajoMaster (run(560)) - ============================================ 2015-02-02 13:02:39,147 INFO: org.apache.tajo.master.TajoMaster (run(561)) - TajoMaster received SIGINT Signal 2015-02-02 13:02:39,148 INFO: org.apache.tajo.master.TajoMaster (run(562)) - ============================================ Feb 2, 2015 12:53:46 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:53:46 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:01 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:01 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:01 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:01 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:01 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers Feb 2, 2015 12:54:04 PM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers 2015-02-02 13:02:39,148 INFO: org.apache.tajo.catalog.CatalogServer (stop(198)) - Catalog Server (127.0.0.1:25884) shutdown 2015-02-02 13:02:39,148 INFO: org.apache.tajo.worker.TajoWorker (run(600)) - ============================================ 2015-02-02 13:02:39,149 INFO: org.apache.tajo.worker.TajoWorker (run(601)) - TajoWorker received SIGINT Signal 2015-02-02 13:02:39,149 INFO: org.apache.tajo.worker.TajoWorker (run(602)) - ============================================ 2015-02-02 13:02:39,153 INFO: org.apache.tajo.session.SessionManager (removeSession(79)) - Session e096e986-3db1-445b-a8c5-9dc775034243 is removed. 2015-02-02 13:02:39,155 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (CatalogProtocol) listened on 127.0.0.1:25884) shutdown 2015-02-02 13:02:39,155 INFO: org.apache.tajo.util.history.HistoryCleaner (run(134)) - History cleaner stopped 2015-02-02 13:02:39,156 INFO: org.apache.tajo.session.SessionManager (removeSession(79)) - Session 2e9e9e2e-0bfd-4391-a353-1bcd070ed5a4 is removed. 2015-02-02 13:02:39,155 INFO: org.apache.tajo.util.history.HistoryWriter (run(265)) - HistoryWriter_asf906.gq1.ygridcore.net_25889 stopped. 2015-02-02 13:02:39,158 INFO: org.apache.tajo.util.history.HistoryWriter (run(265)) - HistoryWriter_127.0.0.1_25886 stopped. 2015-02-02 13:02:39,161 INFO: org.apache.tajo.worker.WorkerHeartbeatService (run(231)) - Worker Resource Heartbeat Thread stopped. 2015-02-02 13:02:39,161 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:25889) shutdown 2015-02-02 13:02:39,161 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (stop(110)) - QueryMasterManagerService stopped 2015-02-02 13:02:39,161 INFO: BlockStateChange (logAddStoredBlock(2383)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48114 is added to blk_1073741835_1011{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-2875e955-213b-4f22-84ef-b335dcca3d84:NORMAL|RBW]]} size 1614 2015-02-02 13:02:39,161 INFO: org.apache.tajo.querymaster.QueryMaster (stop(168)) - QueryMaster stop 2015-02-02 13:02:39,161 INFO: org.apache.tajo.querymaster.QueryMaster (run(469)) - QueryMaster heartbeat thread stopped 2015-02-02 13:02:39,162 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(99)) - TajoWorkerClientService stopping 2015-02-02 13:02:39,165 INFO: org.apache.tajo.util.history.HistoryCleaner (run(134)) - History cleaner stopped 2015-02-02 13:02:39,165 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:25888) shutdown 2015-02-02 13:02:39,165 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(103)) - TajoWorkerClientService stopped 2015-02-02 13:02:39,166 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:25886) shutdown 2015-02-02 13:02:39,166 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:25887) shutdown 2015-02-02 13:02:39,166 INFO: org.apache.tajo.worker.TajoWorkerManagerService (stop(97)) - TajoWorkerManagerService stopped 2015-02-02 13:02:39,166 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:25885) shutdown 2015-02-02 13:02:39,167 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(417)) - TajoWorker main thread exiting 2015-02-02 13:02:39,168 ERROR: org.apache.tajo.master.rm.TajoWorkerResourceManager (run(346)) - java.lang.InterruptedException 2015-02-02 13:02:39,169 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(126)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:25883) shutdown 2015-02-02 13:02:39,170 INFO: org.apache.tajo.master.TajoMaster (stop(394)) - Tajo Master main thread exiting Results : Failed tests: TestCreateTable.testCreatedTableWithQuotedIdentifierAndVerifyPath:139->assertPathOfCreatedTable:111 expected:<hdfs://localhost:54973/tajo/warehouse/D6/OldTable> but was:<hdfs://localhost:54973/tajo/D6/OldTable> TestCreateTable.testCreatedTableJustCreatedAndVerifyPath:133->assertPathOfCreatedTable:111 expected:<hdfs://localhost:54973/tajo/warehouse/d5/old_table> but was:<hdfs://localhost:54973/tajo/d5/old_table> Tests run: 1341, Failures: 2, Errors: 0, Skipped: 0 [INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Tajo Main ......................................... SUCCESS [ 1.741 s] [INFO] Tajo Project POM .................................. SUCCESS [ 1.143 s] [INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.978 s] [INFO] Tajo Common ....................................... SUCCESS [ 24.024 s] [INFO] Tajo Algebra ...................................... SUCCESS [ 1.294 s] [INFO] Tajo Catalog Common ............................... SUCCESS [ 6.471 s] [INFO] Tajo Plan ......................................... SUCCESS [ 5.740 s] [INFO] Tajo Rpc .......................................... SUCCESS [ 25.249 s] [INFO] Tajo Catalog Client ............................... SUCCESS [ 0.959 s] [INFO] Tajo Catalog Server ............................... SUCCESS [ 9.610 s] [INFO] Tajo Storage Common ............................... SUCCESS [ 10.738 s] [INFO] Tajo HDFS Storage ................................. SUCCESS [ 42.822 s] [INFO] Tajo HBase Storage ................................ SUCCESS [ 3.011 s] [INFO] Tajo PullServer ................................... SUCCESS [ 0.818 s] [INFO] Tajo Client ....................................... SUCCESS [ 3.464 s] [INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.808 s] [INFO] ASM (thirdparty) .................................. SUCCESS [ 0.586 s] [INFO] Tajo Core ......................................... FAILURE [14:30 min] [INFO] Tajo Catalog Drivers .............................. SKIPPED [INFO] Tajo Catalog ...................................... SKIPPED [INFO] Tajo Storage ...................................... SKIPPED [INFO] Tajo Distribution ................................. SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 16:52 min [INFO] Finished at: 2015-02-02T13:02:39+00:00 [INFO] Final Memory: 88M/1054M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core: There are test failures. [ERROR] [ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/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 Build step 'Execute shell' marked build as failure Updating TAJO-1317
