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/07/29 13:36:51 UTC

Build failed in Jenkins: Tajo-master-build #780

See <https://builds.apache.org/job/Tajo-master-build/780/changes>

Changes:

[hyunsik] TAJO-1718: Refine code for Parquet 1.8.1.

------------------------------------------
[...truncated 660052 lines...]
2015-07-29 11:37:21,029 INFO: org.apache.tajo.worker.TaskImpl (initPlan(179)) - ==================================
2015-07-29 11:37:21,029 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438168766776_1910_000001_000000_00 is changed to TA_RUNNING
2015-07-29 11:37:21,043 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46614 is added to blk_1073747950_7126{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-25139a9a-064e-4199-8cc7-fe4efd4e0414:NORMAL:127.0.0.1:46614|RBW]]} size 18
2015-07-29 11:37:21,444 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438168766776_1910_000001_000000_00 is changed to TA_SUCCEEDED
2015-07-29 11:37:21,445 INFO: org.apache.tajo.worker.TaskImpl (run(457)) - ta_1438168766776_1910_000001_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-07-29 11:37:21,445 INFO: org.apache.tajo.querymaster.Stage (transition(1282)) - Stage - eb_1438168766776_1910_000001 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-07-29 11:37:21,449 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(158)) - Task Scheduler stopped
2015-07-29 11:37:21,449 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(139)) - TaskScheduler schedulingThread stopped
2015-07-29 11:37:21,450 INFO: org.apache.tajo.querymaster.Stage (transition(1340)) - Stage completed - eb_1438168766776_1910_000001 (total=1, success=1, killed=0)
2015-07-29 11:37:21,450 INFO: org.apache.tajo.querymaster.Query (handle(774)) - Processing q_1438168766776_1910 of type STAGE_COMPLETED
2015-07-29 11:37:21,450 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1438168766776_1910_000002
2015-07-29 11:37:21,450 INFO: org.apache.tajo.querymaster.Query (transition(721)) - Complete Stage[eb_1438168766776_1910_000001], State: SUCCEEDED, 1/1. 
2015-07-29 11:37:21,450 INFO: org.apache.tajo.querymaster.Query (handle(774)) - Processing q_1438168766776_1910 of type QUERY_COMPLETED
2015-07-29 11:37:21,450 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(162)) - Stopped execution block:eb_1438168766776_1910_000001
2015-07-29 11:37:21,452 INFO: org.apache.tajo.querymaster.Query (handle(792)) - q_1438168766776_1910 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-07-29 11:37:21,452 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(294)) - Query completion notified from q_1438168766776_1910 final state: QUERY_SUCCEEDED
2015-07-29 11:37:21,453 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(252)) - Received QueryMaster heartbeat:q_1438168766776_1910,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf900.gq1.ygridcore.net
2015-07-29 11:37:21,453 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1438168766776_1910
2015-07-29 11:37:21,453 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(171)) - Stopping QueryMasterTask:q_1438168766776_1910
2015-07-29 11:37:21,453 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(117)) - =========================================================
2015-07-29 11:37:21,454 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - Stop query:q_1438168766776_1910
2015-07-29 11:37:21,454 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(463)) - Cleanup resources of all workers. Query: q_1438168766776_1910, workers: 1
2015-07-29 11:37:21,454 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(187)) - Stopped QueryMasterTask:q_1438168766776_1910
2015-07-29 11:37:21,599 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(358)) - Saving query summary: hdfs://localhost:44682/tmp/tajo-jenkins/staging/history/20150729/query-detail/q_1438168766776_1910/query.hist
2015-07-29 11:37:21,607 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46614 is added to blk_1073747951_7127{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-25139a9a-064e-4199-8cc7-fe4efd4e0414:NORMAL:127.0.0.1:46614|RBW]]} size 6067
2015-07-29 11:37:21,718 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(575)) - Send result to client for 33f84bd6-4768-49f3-9645-3e9602806635,q_1438168766776_1910, 2 rows
2015-07-29 11:37:21,719 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(575)) - Send result to client for 33f84bd6-4768-49f3-9645-3e9602806635,q_1438168766776_1910, 0 rows
2015-07-29 11:37:21,721 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 33f84bd6-4768-49f3-9645-3e9602806635 is removed.
2015-07-29 11:37:21,722 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(234)) - SQL: DROP TABLE IF EXISTS "TestTajoJdbc".table1
2015-07-29 11:37:21,723 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(277)) - Non Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------


2015-07-29 11:37:21,723 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(279)) - =============================================
2015-07-29 11:37:21,723 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------


2015-07-29 11:37:21,723 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - =============================================
2015-07-29 11:37:21,724 INFO: org.apache.tajo.master.exec.DDLExecutor (dropTable(320)) - relation "TestTajoJdbc.table1" is already exists.
2015-07-29 11:37:21,725 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(234)) - SQL: DROP TABLE IF EXISTS testaltertablepartition
2015-07-29 11:37:21,725 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(277)) - Non Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------


2015-07-29 11:37:21,725 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(279)) - =============================================
2015-07-29 11:37:21,725 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Optimized Query: 

-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------


2015-07-29 11:37:21,725 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - =============================================
2015-07-29 11:37:21,726 INFO: org.apache.tajo.catalog.CatalogServer (dropTable(697)) - relation "TestTajoJdbc.testaltertablepartition" is deleted from the catalog (127.0.0.1:47816)
2015-07-29 11:37:21,726 INFO: org.apache.tajo.master.exec.DDLExecutor (dropTable(338)) - relation "TestTajoJdbc.testaltertablepartition" is  dropped.
2015-07-29 11:37:21,727 INFO: org.apache.tajo.master.exec.DDLExecutor (dropDatabase(191)) - database TestTajoJdbc is dropped.
2015-07-29 11:37:21,728 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session ae4e1293-7043-46c8-9061-20454bc0f0ad is removed.
Tests run: 15, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 6.197 sec - in org.apache.tajo.jdbc.TestTajoJdbc
2015-07-29 11:37:21,739 INFO: org.apache.tajo.worker.TajoWorker (run(565)) - ============================================
2015-07-29 11:37:21,740 INFO: org.apache.tajo.worker.TajoWorker (run(566)) - TajoWorker received SIGINT Signal
2015-07-29 11:37:21,740 INFO: org.apache.tajo.worker.TajoWorker (run(567)) - ============================================
2015-07-29 11:37:21,745 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session ed9ef584-f94f-4116-b568-145454f6efda is removed.
2015-07-29 11:37:21,747 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 5f9d03f5-830d-407b-9e74-e69072b175c3 is removed.
hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 2 records.
Jul 29, 2015 11:22:29 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:29 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 2
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:44 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 29, 2015 11:22:45 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 29, 2015 11:22:46 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 29, 2015 11:22:49 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 212
Jul 29, 2015 11:22:49 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [RLE, BIT_PACKED, PLAIN_DICTIONARY], dic { 3 entries, 12B raw, 3B comp}
Jul 29, 2015 11:22:49 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:49 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate_function] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [RLE, PLAIN, BIT_PACKED]
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 5 records.
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 29, 2015 11:22:50 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 2 ms. row count = 5
2015-07-29 11:37:21,748 INFO: org.apache.tajo.master.TajoMaster (run(567)) - ============================================
2015-07-29 11:37:21,751 INFO: org.apache.tajo.master.TajoMaster (run(568)) - TajoMaster received SIGINT Signal
2015-07-29 11:37:21,751 INFO: org.apache.tajo.master.TajoMaster (run(569)) - ============================================
2015-07-29 11:37:21,753 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (Tajo-REST) listened on 0:0:0:0:0:0:0:0:47819) shutdown
2015-07-29 11:37:21,754 WARN: org.apache.hadoop.hdfs.DFSClient (completeFile(2275)) - Caught exception 
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.DFSOutputStream.completeFile(DFSOutputStream.java:2269)
	at org.apache.hadoop.hdfs.DFSOutputStream.close(DFSOutputStream.java:2234)
	at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:72)
	at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:106)
	at org.apache.hadoop.io.IOUtils.cleanup(IOUtils.java:237)
	at org.apache.tajo.util.history.HistoryWriter$WriterThread.writeQueryHistory(HistoryWriter.java:362)
	at org.apache.tajo.util.history.HistoryWriter$WriterThread.writeHistory(HistoryWriter.java:311)
	at org.apache.tajo.util.history.HistoryWriter$WriterThread.run(HistoryWriter.java:237)
2015-07-29 11:37:21,754 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2015-07-29 11:37:21,754 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-07-29 11:37:21,757 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(191)) - Catalog Server (127.0.0.1:47816) shutdown
2015-07-29 11:37:21,758 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (CatalogProtocol) listened on 127.0.0.1:47816) shutdown
2015-07-29 11:37:21,759 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_127.0.0.1_47818 stopped.
2015-07-29 11:37:21,763 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:44682/tmp/tajo-jenkins/staging/history/20150729/query-detail/q_1438168766776_1910/eb_1438168766776_1910_000001.hist
2015-07-29 11:37:21,763 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46614 is added to blk_1073741834_1010{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-f01d96cd-499a-4f9a-9e3f-981dbe813808:NORMAL:127.0.0.1:46614|RBW]]} size 704
2015-07-29 11:37:21,764 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-07-29 11:37:21,764 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:47818) shutdown
2015-07-29 11:37:21,766 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:47817) shutdown
2015-07-29 11:37:21,768 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:47815) shutdown
2015-07-29 11:37:21,769 INFO: org.apache.tajo.master.TajoMaster (serviceStop(401)) - Tajo Master main thread exiting
2015-07-29 11:37:21,770 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46614 is added to blk_1073747952_7128{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-25139a9a-064e-4199-8cc7-fe4efd4e0414:NORMAL:127.0.0.1:46614|RBW]]} size 518
2015-07-29 11:37:22,172 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_asf900.gq1.ygridcore.net_47820 stopped.
2015-07-29 11:37:22,184 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped.
2015-07-29 11:37:22,184 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped.
2015-07-29 11:37:22,185 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:47822) shutdown
2015-07-29 11:37:22,185 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-07-29 11:37:22,186 INFO: org.apache.tajo.querymaster.QueryMaster (run(417)) - QueryMaster heartbeat thread stopped
2015-07-29 11:37:22,188 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(168)) - QueryMaster stopped
2015-07-29 11:37:22,188 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(99)) - TajoWorkerClientService stopping
2015-07-29 11:37:22,189 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:47821) shutdown
2015-07-29 11:37:22,189 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(103)) - TajoWorkerClientService stopped
2015-07-29 11:37:22,189 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:47820) shutdown
2015-07-29 11:37:22,190 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-07-29 11:37:22,190 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(375)) - TajoWorker main thread exiting

Results :

Tests in error: 
  TestGroupByQuery.testDistinctAggregation3:269->QueryTestCaseBase.executeQuery:397->QueryTestCaseBase.executeFile:591 » SQL

Tests run: 1561, Failures: 0, Errors: 1, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  1.528 s]
[INFO] Tajo Project POM .................................. SUCCESS [  1.158 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  2.661 s]
[INFO] Tajo Common ....................................... SUCCESS [ 29.559 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  1.413 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  4.925 s]
[INFO] Tajo Plan ......................................... SUCCESS [  4.865 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  0.414 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 47.161 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.336 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [  9.661 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 10.487 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 55.233 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  4.331 s]
[INFO] Tajo PullServer ................................... SUCCESS [  1.045 s]
[INFO] Tajo Client ....................................... SUCCESS [  1.836 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  1.108 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [  3.148 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  0.739 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  3.325 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  0.951 s]
[INFO] Tajo Core ......................................... FAILURE [18:27 min]
[INFO] Tajo RPC .......................................... SKIPPED
[INFO] Tajo Catalog Drivers Hive ......................... SKIPPED
[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: 21:34 min
[INFO] Finished at: 2015-07-29T11:37:22+00:00
[INFO] Final Memory: 67M/479M
[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-1718

Build failed in Jenkins: Tajo-master-build #782

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/782/changes>

Changes:

[jihoonson] TAJO-1300: Merge the index branch into the master branch.

------------------------------------------
[...truncated 161061 lines...]
2015-07-30 05:15:43,550 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(998)) - eb_1438233016309_0502_000001, The determined number of partitions is 1
2015-07-30 05:15:43,550 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(866)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1438233016309_0502_000001
2015-07-30 05:15:43,552 INFO: org.apache.tajo.storage.FileTablespace (listStatus(384)) - Total input paths to process : 2
2015-07-30 05:15:43,555 INFO: org.apache.tajo.storage.FileTablespace (getSplits(588)) - Total # of splits: 2
2015-07-30 05:15:43,556 INFO: org.apache.tajo.querymaster.Stage (run(818)) - 2 objects are scheduled
2015-07-30 05:15:43,556 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(104)) - Start TaskScheduler
2015-07-30 05:15:43,557 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(760)) - Assigned Local/Rack/Cancel/Total: (0/1/0/1), Locality: 0.00%, Rack host: asf904.gq1.ygridcore.net
2015-07-30 05:15:43,572 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(113)) - QueryMaster Address:asf904.gq1.ygridcore.net:22627
2015-07-30 05:15:43,572 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (allocateRackTask(760)) - Assigned Local/Rack/Cancel/Total: (0/2/0/2), Locality: 0.00%, Rack host: asf904.gq1.ygridcore.net
2015-07-30 05:15:43,574 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:34500/tajo
2015-07-30 05:15:43,574 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir>
2015-07-30 05:15:43,575 INFO: org.apache.tajo.worker.TaskManager (handle(183)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:500, Disks:1, vCores:1)
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1)>
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000000_00 is changed to TA_PENDING
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000001_000000_00
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1)>
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000001_00 is changed to TA_PENDING
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000001_000001_00
2015-07-30 05:15:43,576 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000001_000000_00 is initialized
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0>
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000001_000001_00 is initialized
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0>
2015-07-30 05:15:43,578 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,577 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000000_00 is changed to TA_RUNNING
2015-07-30 05:15:43,578 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000001_00 is changed to TA_RUNNING
2015-07-30 05:15:43,581 INFO: org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(74)) - Output data directory: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output>
2015-07-30 05:15:43,581 INFO: org.apache.tajo.engine.planner.physical.RangeShuffleFileWriteExec (init(74)) - Output data directory: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output>
2015-07-30 05:15:43,609 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000001_000000_00] Chunks creation time: 1 msec
2015-07-30 05:15:43,611 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000001_000001_00] Chunks creation time: 1 msec
2015-07-30 05:15:43,619 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000001_00 is changed to TA_SUCCEEDED
2015-07-30 05:15:43,619 INFO: org.apache.tajo.worker.TaskImpl (run(456)) - ta_1438233016309_0502_000001_000001_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-07-30 05:15:43,619 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000001_000000_00 is changed to TA_SUCCEEDED
2015-07-30 05:15:43,620 INFO: org.apache.tajo.worker.TaskImpl (run(456)) - ta_1438233016309_0502_000001_000000_00 completed. Worker's task counter - total:2, succeeded: 2, killed: 0, failed: 0
2015-07-30 05:15:43,620 INFO: org.apache.tajo.querymaster.Stage (transition(1180)) - [eb_1438233016309_0502_000001] Task Completion Event (Total: 2, Success: 1, Killed: 0, Failed: 0)
2015-07-30 05:15:43,620 INFO: org.apache.tajo.querymaster.Stage (transition(1282)) - Stage - eb_1438233016309_0502_000001 finalize RANGE_SHUFFLE (total=2, success=2, killed=0)
2015-07-30 05:15:43,620 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(158)) - Task Scheduler stopped
2015-07-30 05:15:43,620 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(139)) - TaskScheduler schedulingThread stopped
2015-07-30 05:15:43,621 INFO: org.apache.tajo.querymaster.Stage (transition(1340)) - Stage completed - eb_1438233016309_0502_000001 (total=2, success=2, killed=0)
2015-07-30 05:15:43,621 INFO: org.apache.tajo.querymaster.Query (handle(820)) - Processing q_1438233016309_0502 of type STAGE_COMPLETED
2015-07-30 05:15:43,621 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1438233016309_0502_000002
2015-07-30 05:15:43,621 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(162)) - Stopped execution block:eb_1438233016309_0502_000001
2015-07-30 05:15:43,621 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(722)) - Scheduling Stage:eb_1438233016309_0502_000002
2015-07-30 05:15:43,622 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(866)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1438233016309_0502_000002
2015-07-30 05:15:43,622 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1028)) - eb_1438233016309_0502_000002, Table's volume is approximately 1 MB
2015-07-30 05:15:43,622 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1032)) - eb_1438233016309_0502_000002, The determined number of non-leaf tasks is 1
2015-07-30 05:15:43,629 INFO: org.apache.tajo.querymaster.Stage (run(818)) - 5 objects are scheduled
2015-07-30 05:15:43,629 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(104)) - Start TaskScheduler
2015-07-30 05:15:43,632 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(113)) - QueryMaster Address:asf904.gq1.ygridcore.net:22627
2015-07-30 05:15:43,634 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:34500/tajo
2015-07-30 05:15:43,634 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir>
2015-07-30 05:15:43,635 INFO: org.apache.tajo.worker.TaskManager (handle(183)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:0, Disks:3, vCores:0)
2015-07-30 05:15:43,636 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2)>
2015-07-30 05:15:43,636 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000004_00 is changed to TA_PENDING
2015-07-30 05:15:43,636 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000002_000004_00
2015-07-30 05:15:43,636 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2)>
2015-07-30 05:15:43,636 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000002_00 is changed to TA_PENDING
2015-07-30 05:15:43,637 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(310)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000004-000
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000004-000
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000002_000002_00
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2)>
2015-07-30 05:15:43,637 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(310)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000002-000
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000002-000
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000002_000004_00 is initialized
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000003_00 is changed to TA_PENDING
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000002_000002_00 is initialized
2015-07-30 05:15:43,637 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:2) :
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2/4_0>
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:2) :
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2/2_0>
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,638 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000002_000003_00
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created  <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/in/eb_1438233016309_0502_000002/4/0/eb_1438233016309_0502_000001>
2015-07-30 05:15:43,639 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(310)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000003-000
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000003-000
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created  <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/in/eb_1438233016309_0502_000002/2/0/eb_1438233016309_0502_000001>
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000002_000003_00 is initialized
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:2) :
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2/3_0>
2015-07-30 05:15:43,640 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,640 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,639 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[0_0]
2015-07-30 05:15:43,640 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[0_0]
2015-07-30 05:15:43,640 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created  <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/in/eb_1438233016309_0502_000002/3/0/eb_1438233016309_0502_000001>
2015-07-30 05:15:43,641 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,641 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,641 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[1_0]
2015-07-30 05:15:43,685 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((000), (049)
2015-07-30 05:15:43,685 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((050), (099)
2015-07-30 05:15:43,685 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output> (start=(060), end=(080))
2015-07-30 05:15:43,685 WARN: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(720)) - Out of Scope (indexed data [(000), (049)], but request start:(060), end: (080)
2015-07-30 05:15:43,685 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output> (start=(080), end=(099), last=true)
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[0_0]
2015-07-30 05:15:43,686 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=570, length=380, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(716)) - Create a new Fetcher with storeChunk: (start=570, length=380, fromRemote=false, ebId=eb_1438233016309_0502_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,686 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,687 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[1_0]
2015-07-30 05:15:43,689 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((050), (099)
2015-07-30 05:15:43,689 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output> (start=(040), end=(060))
2015-07-30 05:15:43,691 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=0, length=190, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,691 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(716)) - Create a new Fetcher with storeChunk: (start=0, length=190, fromRemote=false, ebId=eb_1438233016309_0502_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,692 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,692 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,692 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[1_0]
2015-07-30 05:15:43,707 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((000), (049)
2015-07-30 05:15:43,707 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output> (start=(080), end=(099), last=true)
2015-07-30 05:15:43,707 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((050), (099)
2015-07-30 05:15:43,707 WARN: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(720)) - Out of Scope (indexed data [(000), (049)], but request start:(080), end: (099)
2015-07-30 05:15:43,707 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output> (start=(060), end=(080))
2015-07-30 05:15:43,707 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000004_00 is changed to TA_RUNNING
2015-07-30 05:15:43,707 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (run(612)) - Add a new FileChunk to local chunk list
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(358)) - ta_1438233016309_0502_000002_000004_00 All fetches are done!
2015-07-30 05:15:43,708 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=190, length=380, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(716)) - Create a new Fetcher with storeChunk: (start=190, length=380, fromRemote=false, ebId=eb_1438233016309_0502_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output>
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000003_00 is changed to TA_RUNNING
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (run(612)) - Add a new FileChunk to local chunk list
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(568)) - One local chunk is added to listTablets
2015-07-30 05:15:43,708 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(358)) - ta_1438233016309_0502_000002_000003_00 All fetches are done!
2015-07-30 05:15:43,709 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(568)) - One local chunk is added to listTablets
2015-07-30 05:15:43,718 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((000), (049)
2015-07-30 05:15:43,718 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output> (start=(040), end=(060))
2015-07-30 05:15:43,719 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=750, length=190, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output>
2015-07-30 05:15:43,719 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(716)) - Create a new Fetcher with storeChunk: (start=750, length=190, fromRemote=false, ebId=eb_1438233016309_0502_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output>
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000002_00 is changed to TA_RUNNING
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.TaskImpl (run(612)) - Add a new FileChunk to local chunk list
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.TaskImpl (run(612)) - Add a new FileChunk to local chunk list
2015-07-30 05:15:43,720 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(358)) - ta_1438233016309_0502_000002_000002_00 All fetches are done!
2015-07-30 05:15:43,721 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(568)) - One local chunk is added to listTablets
2015-07-30 05:15:43,721 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(568)) - One local chunk is added to listTablets
2015-07-30 05:15:43,733 INFO: org.apache.tajo.storage.hbase.HFileAppender (init(84)) - Created hbase file writer: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/_temporary/0/_temporary/attempt_q_1438233016309_0502_0002_m_000003_0
2015-07-30 05:15:43,733 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000002_000003_00] Total merge time: 0 msec
2015-07-30 05:15:43,734 INFO: org.apache.tajo.storage.hbase.HFileAppender (init(84)) - Created hbase file writer: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/_temporary/0/_temporary/attempt_q_1438233016309_0502_0002_m_000004_0
2015-07-30 05:15:43,734 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000002_000004_00] Total merge time: 0 msec
2015-07-30 05:15:43,744 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:45581 is added to blk_1073742927_2103{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-b0f2aaa6-4c93-469f-a32a-bf237c5658e7:NORMAL:127.0.0.1:45581|RBW]]} size 0
2015-07-30 05:15:43,746 INFO: org.apache.tajo.storage.hbase.HFileAppender (init(84)) - Created hbase file writer: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/_temporary/0/_temporary/attempt_q_1438233016309_0502_0002_m_000002_0
2015-07-30 05:15:43,746 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:45581 is added to blk_1073742928_2104{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-f241d786-da60-4165-b8ee-2e8a27002d9b:NORMAL:127.0.0.1:45581|RBW]]} size 5432
2015-07-30 05:15:43,746 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000002_000002_00] Total merge time: 0 msec
2015-07-30 05:15:43,748 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000004_00 is changed to TA_SUCCEEDED
2015-07-30 05:15:43,750 INFO: org.apache.tajo.worker.TaskImpl (run(456)) - ta_1438233016309_0502_000002_000004_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-07-30 05:15:43,751 INFO: org.apache.tajo.querymaster.Stage (transition(1180)) - [eb_1438233016309_0502_000002] Task Completion Event (Total: 5, Success: 1, Killed: 0, Failed: 0)
2015-07-30 05:15:43,755 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:45581 is added to blk_1073742929_2105{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-b0f2aaa6-4c93-469f-a32a-bf237c5658e7:NORMAL:127.0.0.1:45581|RBW]]} size 5432
2015-07-30 05:15:43,790 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2)>
2015-07-30 05:15:43,790 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000001_00 is changed to TA_PENDING
2015-07-30 05:15:43,791 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1438233016309_0502_000002_000001_00
2015-07-30 05:15:43,791 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(310)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000001-000
2015-07-30 05:15:43,791 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/part-02-000001-000
2015-07-30 05:15:43,791 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-07-30 05:15:43,791 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1438233016309_0502_000002_000001_00 is initialized
2015-07-30 05:15:43,792 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:2) :
2015-07-30 05:15:43,792 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/2/1_0>
2015-07-30 05:15:43,792 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-07-30 05:15:43,792 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created  <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/in/eb_1438233016309_0502_000002/1/0/eb_1438233016309_0502_000001>
2015-07-30 05:15:43,793 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,793 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,793 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[1_0]
2015-07-30 05:15:43,815 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((000), (049)
2015-07-30 05:15:43,816 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output> (start=(010), end=(040))
2015-07-30 05:15:43,816 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk:  (start=180, length=570, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output>
2015-07-30 05:15:43,816 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(716)) - Create a new Fetcher with storeChunk: (start=180, length=570, fromRemote=false, ebId=eb_1438233016309_0502_000001) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/1_0/output/output>
2015-07-30 05:15:43,817 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(688)) - Try to get local file chunk at local host
2015-07-30 05:15:43,817 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(730)) - getLocalStoredFileChunk starts
2015-07-30 05:15:43,817 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(765)) - PullServer request param: shuffleType=r, sid=1, partId=0, taskIds=[0_0]
2015-07-30 05:15:43,836 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((050), (099)
2015-07-30 05:15:43,836 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/4c8fb6a3-81e6-4671-8a61-9138760d567f/tajo-localdir/q_1438233016309_0502/output/1/0_0/output/output> (start=(010), end=(040))
2015-07-30 05:15:43,836 WARN: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(720)) - Out of Scope (indexed data [(050), (099)], but request start:(010), end: (040)
2015-07-30 05:15:43,836 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(137)) - Query status of ta_1438233016309_0502_000002_000001_00 is changed to TA_RUNNING
2015-07-30 05:15:43,836 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-07-30 05:15:43,836 INFO: org.apache.tajo.worker.TaskImpl (run(612)) - Add a new FileChunk to local chunk list
2015-07-30 05:15:43,836 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(358)) - ta_1438233016309_0502_000002_000001_00 All fetches are done!
2015-07-30 05:15:43,837 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(568)) - One local chunk is added to listTablets
2015-07-30 05:15:43,855 INFO: org.apache.tajo.storage.hbase.HFileAppender (init(84)) - Created hbase file writer: hdfs://localhost:34500/tmp/tajo-jenkins/staging/q_1438233016309_0502/RESULT/_temporary/0/_temporary/attempt_q_1438233016309_0502_0002_m_000001_0
2015-07-30 05:15:43,855 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1438233016309_0502_000002_000001_00] Total merge time: 0 msec
2015-07-30 05:15:43,866 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:45581 is added to blk_1073742930_2106{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-b0f2aaa6-4c93-469f-a32a-bf237c5658e7:NORMAL:127.0.0.1:45581|RBW]]} size 5792
Killed

Results :

Tests run: 567, Failures: 0, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  2.357 s]
[INFO] Tajo Project POM .................................. SUCCESS [  2.102 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  3.493 s]
[INFO] Tajo Common ....................................... SUCCESS [ 38.333 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  2.053 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  7.292 s]
[INFO] Tajo Plan ......................................... SUCCESS [  8.286 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  0.566 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 49.371 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.575 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 13.832 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 12.335 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 57.752 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  4.600 s]
[INFO] Tajo PullServer ................................... SUCCESS [  1.115 s]
[INFO] Tajo Client ....................................... SUCCESS [  1.946 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  1.525 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [  3.490 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  1.033 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  4.856 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  1.111 s]
[INFO] Tajo Core ......................................... FAILURE [06:13 min]
[INFO] Tajo RPC .......................................... SKIPPED
[INFO] Tajo Catalog Drivers Hive ......................... SKIPPED
[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: 09:53 min
[INFO] Finished at: 2015-07-30T05:15:43+00:00
[INFO] Final Memory: 100M/484M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core> && /home/jenkins/tools/java/jdk1.7.0_25-32/jre/bin/java -Xms512m -Xmx1024m -XX:MaxPermSize=152m -Dfile.encoding=UTF-8 -jar <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire/surefirebooter5785341424498011541.jar> <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire/surefire6107385733893930030tmp> <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire/surefire_122475920405264881155tmp>
[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/PluginExecutionException
[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-1300


Build failed in Jenkins: Tajo-master-build #781

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/781/changes>

Changes:

[jihoonson] TAJO-1713: Change the type of edge cache in JoinGraphContext from HashMap to LRUMap.

------------------------------------------
[...truncated 660054 lines...]
INFO: 1 * Client response received on thread main
1 < 400
1 < Content-Type: application/json

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Sending client request on thread main
1 > DELETE http://127.0.0.1:25668/rest/databases/TestDropDatabaseNotFound

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 58 * Server has received a request on thread Tajo-REST-5 Server Worker #1
58 > DELETE http://127.0.0.1:25668/rest/databases/TestDropDatabaseNotFound
58 > Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
58 > Connection: keep-alive
58 > Content-Length: 0
58 > Host: 127.0.0.1:25668
58 > User-Agent: Jersey/2.6 (HttpUrlConnection 1.7.0_25)

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 58 * Server responded with a response on thread Tajo-REST-5 Server Worker #1
58 < 404

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Client response received on thread main
1 < 404

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Sending client request on thread main
1 > GET http://127.0.0.1:25668/rest/databases/testGetDatabaseNotFound

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 59 * Server has received a request on thread Tajo-REST-5 Server Worker #0
59 > GET http://127.0.0.1:25668/rest/databases/testGetDatabaseNotFound
59 > Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
59 > Connection: keep-alive
59 > Content-Length: 0
59 > Host: 127.0.0.1:25668
59 > User-Agent: Jersey/2.6 (HttpUrlConnection 1.7.0_25)

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 59 * Server responded with a response on thread Tajo-REST-5 Server Worker #0
59 < 404

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Client response received on thread main
1 < 404

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Sending client request on thread main
1 > POST http://127.0.0.1:25668/rest/databases
1 > Content-Type: application/json

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 60 * Server has received a request on thread Tajo-REST-5 Server Worker #1
60 > POST http://127.0.0.1:25668/rest/databases
60 > Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
60 > Connection: keep-alive
60 > Content-Length: 40
60 > Content-Type: application/json
60 > Host: 127.0.0.1:25668
60 > User-Agent: Jersey/2.6 (HttpUrlConnection 1.7.0_25)

2015-07-30 02:22:12,861 INFO: org.apache.tajo.catalog.CatalogServer (createDatabase(393)) - database "TestDatabasesResource" is created
Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 60 * Server responded with a response on thread Tajo-REST-5 Server Worker #1
60 < 201
60 < Location: http://127.0.0.1:25668/rest/databases/TestDatabasesResource

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Client response received on thread main
1 < 201
1 < Location: http://127.0.0.1:25668/rest/databases/TestDatabasesResource

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 2 * Sending client request on thread main
2 > GET http://127.0.0.1:25668/rest/databases

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 61 * Server has received a request on thread Tajo-REST-5 Server Worker #0
61 > GET http://127.0.0.1:25668/rest/databases
61 > Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
61 > Connection: keep-alive
61 > Content-Length: 0
61 > Host: 127.0.0.1:25668
61 > User-Agent: Jersey/2.6 (HttpUrlConnection 1.7.0_25)

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 61 * Server responded with a response on thread Tajo-REST-5 Server Worker #0
61 < 200
61 < Content-Type: application/json

Jul 30, 2015 2:22:12 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 2 * Client response received on thread main
2 < 200
2 < Content-Type: application/json

2015-07-30 02:22:12,866 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 4a77969b-d41a-42fd-9476-872625ce1ab3 is removed.
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.188 sec - in org.apache.tajo.ws.rs.resources.TestDatabasesResource
eader initialized will read a total of 2 records.
Jul 30, 2015 2:14:20 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:20 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 2
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:38 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:39 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 3 ms. row count = 1
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records.
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:40 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 212
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 3 entries, 12B raw, 3B comp}
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate_function] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, RLE, PLAIN]
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 5 records.
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 30, 2015 2:14:43 AM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 0 ms. row count = 5
2015-07-30 02:22:12,876 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 9ccfb47b-4690-44de-aff0-602abdb6b530 is removed.
2015-07-30 02:22:12,876 INFO: org.apache.tajo.master.TajoMaster (run(567)) - ============================================
2015-07-30 02:22:12,876 INFO: org.apache.tajo.master.TajoMaster (run(568)) - TajoMaster received SIGINT Signal
2015-07-30 02:22:12,876 INFO: org.apache.tajo.master.TajoMaster (run(569)) - ============================================
2015-07-30 02:22:12,877 INFO: org.apache.tajo.worker.TajoWorker (run(565)) - ============================================
2015-07-30 02:22:12,877 INFO: org.apache.tajo.worker.TajoWorker (run(566)) - TajoWorker received SIGINT Signal
2015-07-30 02:22:12,877 INFO: org.apache.tajo.worker.TajoWorker (run(567)) - ============================================
2015-07-30 02:22:12,880 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_asf904.gq1.ygridcore.net_25669 stopped.
2015-07-30 02:22:12,880 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-07-30 02:22:12,881 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped.
2015-07-30 02:22:12,881 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped.
2015-07-30 02:22:12,881 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 876a7faf-e823-4718-b54a-814b4ef5d0e6 is removed.
2015-07-30 02:22:12,881 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (Tajo-REST) listened on 0:0:0:0:0:0:0:0:25668) shutdown
2015-07-30 02:22:12,881 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2015-07-30 02:22:12,882 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(191)) - Catalog Server (127.0.0.1:25665) shutdown
2015-07-30 02:22:12,882 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (CatalogProtocol) listened on 127.0.0.1:25665) shutdown
2015-07-30 02:22:12,883 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_127.0.0.1_25667 stopped.
2015-07-30 02:22:12,885 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:25671) shutdown
2015-07-30 02:22:12,886 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2015-07-30 02:22:12,886 INFO: org.apache.tajo.querymaster.QueryMaster (run(417)) - QueryMaster heartbeat thread stopped
2015-07-30 02:22:12,889 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(168)) - QueryMaster stopped
2015-07-30 02:22:12,889 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(99)) - TajoWorkerClientService stopping
2015-07-30 02:22:12,890 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:25670) shutdown
2015-07-30 02:22:12,890 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(103)) - TajoWorkerClientService stopped
2015-07-30 02:22:12,890 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:25669) shutdown
2015-07-30 02:22:12,890 INFO: BlockStateChange (logAddStoredBlock(2473)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49483 is added to blk_1073741834_1010{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-b1976170-27fa-4b99-bdce-ddd2a235cf70:NORMAL:127.0.0.1:49483|RBW]]} size 3013017
2015-07-30 02:22:12,890 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2015-07-30 02:22:12,891 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(375)) - TajoWorker main thread exiting
2015-07-30 02:22:13,291 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2015-07-30 02:22:13,292 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:25667) shutdown
2015-07-30 02:22:13,293 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:25666) shutdown
2015-07-30 02:22:13,296 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:25664) shutdown
2015-07-30 02:22:13,296 INFO: org.apache.tajo.master.TajoMaster (serviceStop(401)) - Tajo Master main thread exiting

Results :

Tests in error: 
  TestOuterJoinQuery.testLeftOuterWithEmptyTable:347->QueryTestCaseBase.runSimpleTests:527 » SQL

Tests run: 1561, Failures: 0, Errors: 1, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Tajo Main ......................................... SUCCESS [  1.857 s]
[INFO] Tajo Project POM .................................. SUCCESS [  2.167 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [  2.813 s]
[INFO] Tajo Common ....................................... SUCCESS [ 32.622 s]
[INFO] Tajo Algebra ...................................... SUCCESS [  1.696 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [  5.680 s]
[INFO] Tajo Plan ......................................... SUCCESS [  5.479 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [  0.467 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 49.332 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [  1.543 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 11.208 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 10.752 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 56.671 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [  4.603 s]
[INFO] Tajo PullServer ................................... SUCCESS [  1.238 s]
[INFO] Tajo Client ....................................... SUCCESS [  2.110 s]
[INFO] Tajo CLI tools .................................... SUCCESS [  0.958 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [  3.458 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [  1.357 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [  3.594 s]
[INFO] Tajo Metrics ...................................... SUCCESS [  1.082 s]
[INFO] Tajo Core ......................................... FAILURE [19:39 min]
[INFO] Tajo RPC .......................................... SKIPPED
[INFO] Tajo Catalog Drivers Hive ......................... SKIPPED
[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: 23:01 min
[INFO] Finished at: 2015-07-30T02:22:13+00:00
[INFO] Final Memory: 67M/492M
[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-1713