See <https://builds.apache.org/job/Tajo-master-jdk8-nightly/112/changes>
Changes: [hyunsik] TAJO-1790: TestTajoClientV2::testExecuteQueryAsyncWithListener occasionally is failed. [hyunsik] TAJO-1741: Two tables having same time zone display different timestamps. [hyunsik] TAJO-1792: tajo-cluster-tests is not available when it is used as an external maven module. [hyunsik] TAJO-1787: Remove unused and legacy exceptions. [hyunsik] TAJO-1737: Implement SQL Parser rule for Map type. [jhkim] TAJO-1596: TestPythonFunctions occasionally fails. [jhkim] TAJO-1783: Query result is not returned by invalid output path. ------------------------------------------ [...truncated 727795 lines...] 2015-08-21 19:14:57,533 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2) 2015-08-21 19:14:57,533 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/4)> 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1440183233682_2058_000004_000000_00 is changed to TA_PENDING 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1440183233682_2058_000004_000000_00 2015-08-21 19:14:57,534 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:53245/tmp/tajo-jenkins/staging/q_1440183233682_2058/RESULT/part-04-000000-000 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:53245/tmp/tajo-jenkins/staging/q_1440183233682_2058/RESULT/part-04-000000-000 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ================================== 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1440183233682_2058_000004_000000_00 is initialized 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 1), Fetches (total:1) : 2015-08-21 19:14:57,534 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/4/0_0> 2015-08-21 19:14:57,535 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ================================== 2015-08-21 19:14:57,535 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/in/eb_1440183233682_2058_000004/0/0/eb_1440183233682_2058_000003> 2015-08-21 19:14:57,536 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host 2015-08-21 19:14:57,536 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts 2015-08-21 19:14:57,536 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=r, sid=3, partId=0, taskIds=[0_0] 2015-08-21 19:14:57,560 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(686)) - BSTIndex is loaded from disk ((1,1), (5,NULL) 2015-08-21 19:14:57,560 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(710)) - GET Request for <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/3/0_0/output/output> (start=(1,1), end=(5,NULL), last=true) 2015-08-21 19:14:57,560 INFO: org.apache.tajo.pullserver.TajoPullServerService (getFileChunks(779)) - Retrieve File Chunk: (start=0, length=49, fromRemote=false, ebId=null) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/3/0_0/output/output> 2015-08-21 19:14:57,560 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=49, fromRemote=false, ebId=eb_1440183233682_2058_000003) <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/3/0_0/output/output> 2015-08-21 19:14:57,561 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1440183233682_2058_000004_000000_00 is changed to TA_RUNNING 2015-08-21 19:14:57,561 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host 2015-08-21 19:14:57,561 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list 2015-08-21 19:14:57,561 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(362)) - ta_1440183233682_2058_000004_000000_00 All fetches are done! 2015-08-21 19:14:57,562 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets 2015-08-21 19:14:57,564 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) - [ta_1440183233682_2058_000004_000000_00] Total merge time: 0 msec 2015-08-21 19:14:57,564 INFO: org.apache.tajo.engine.planner.physical.ExternalSortExec (close(796)) - Delete file: "fragment": {"id": "eb_1440183233682_2058_000003", "path": <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/test-data/a7846be0-d9e3-4d0b-9ba3-0240003da36b/tajo-localdir/q_1440183233682_2058/output/3/0_0/output/output";,> "start": 0,"length": 49} 2015-08-21 19:14:57,567 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33628 is added to blk_1073748618_7794{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-52df8432-30ed-4935-b15c-399d06c34052:NORMAL:127.0.0.1:33628|FINALIZED]]} size 0 2015-08-21 19:14:57,567 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1440183233682_2058_000004_000000_00 is changed to TA_SUCCEEDED 2015-08-21 19:14:57,568 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1440183233682_2058_000004_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0 2015-08-21 19:14:57,568 INFO: org.apache.tajo.querymaster.Stage (transition(1298)) - Stage - eb_1440183233682_2058_000004 finalize NONE_SHUFFLE (total=1, success=1, killed=0) 2015-08-21 19:14:57,568 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped 2015-08-21 19:14:57,568 INFO: org.apache.tajo.querymaster.Stage (transition(1356)) - Stage completed - eb_1440183233682_2058_000004 (total=1, success=1, killed=0) 2015-08-21 19:14:57,568 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1440183233682_2058 of type STAGE_COMPLETED 2015-08-21 19:14:57,568 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1440183233682_2058_000005 2015-08-21 19:14:57,569 INFO: org.apache.tajo.querymaster.Query (transition(802)) - Complete Stage[eb_1440183233682_2058_000004], State: SUCCEEDED, 4/4. 2015-08-21 19:14:57,569 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1440183233682_2058 of type QUERY_COMPLETED 2015-08-21 19:14:57,568 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(122)) - TaskScheduler schedulingThread stopped 2015-08-21 19:14:57,569 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1440183233682_2058_000004 2015-08-21 19:14:57,569 INFO: org.apache.tajo.querymaster.Query (finalizeQuery(528)) - Can't find partitions for adding. 2015-08-21 19:14:57,570 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1440183233682_2058 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED 2015-08-21 19:14:57,570 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(295)) - Query completion notified from q_1440183233682_2058 final state: QUERY_SUCCEEDED 2015-08-21 19:14:57,570 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(252)) - Received QueryMaster heartbeat:q_1440183233682_2058,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf906.gq1.ygridcore.net 2015-08-21 19:14:57,570 INFO: org.apache.tajo.master.QueryManager (stopQuery(276)) - Stop QueryInProgress:q_1440183233682_2058 2015-08-21 19:14:57,570 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(117)) - ========================================================= 2015-08-21 19:14:57,570 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - Stop query:q_1440183233682_2058 2015-08-21 19:14:57,570 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(172)) - Stopping QueryMasterTask:q_1440183233682_2058 2015-08-21 19:14:57,570 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(471)) - Cleanup resources of all workers. Query: q_1440183233682_2058, workers: 1 2015-08-21 19:14:57,571 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(188)) - Stopped QueryMasterTask:q_1440183233682_2058 2015-08-21 19:14:57,641 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1 2015-08-21 19:14:57,642 INFO: org.apache.tajo.storage.FileTablespace (getSplits(572)) - Total # of splits: 1 2015-08-21 19:14:57,644 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 19581a0d-9ead-4aa4-8500-ce63849fb449,q_1440183233682_2058, 5 rows 2015-08-21 19:14:57,645 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 19581a0d-9ead-4aa4-8500-ce63849fb449,q_1440183233682_2058, 0 rows 2015-08-21 19:14:57,646 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 19581a0d-9ead-4aa4-8500-ce63849fb449 is removed. 2015-08-21 19:14:57,649 INFO: org.apache.tajo.session.SessionManager (createSession(80)) - Session 5144d40f-e5dd-4c4d-9bce-ceafb3b26dcd is created. 2015-08-21 19:14:57,650 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(177)) - Query: create table "TEST_DESC_TABLE" (col1 int4, col2 int4) 2015-08-21 19:14:57,651 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - Non Optimized Query: ----------------------------- Query Block Graph ----------------------------- |-#ROOT ----------------------------- Optimization Log: ----------------------------- 2015-08-21 19:14:57,651 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - ============================================= 2015-08-21 19:14:57,651 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - Optimized Query: ----------------------------- Query Block Graph ----------------------------- |-#ROOT ----------------------------- Optimization Log: ----------------------------- 2015-08-21 19:14:57,652 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(286)) - ============================================= 2015-08-21 19:14:57,653 INFO: org.apache.tajo.catalog.CatalogServer (createTable(667)) - relation "default.TEST_DESC_TABLE" is added to the catalog (127.0.0.1:16414) 2015-08-21 19:14:57,656 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 5144d40f-e5dd-4c4d-9bce-ceafb3b26dcd is removed. Tests run: 21, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.442 sec - in org.apache.tajo.cli.tsql.TestTajoCli 2015-08-21 19:14:57,662 INFO: org.apache.tajo.master.TajoMaster (run(538)) - ============================================ 2015-08-21 19:14:57,662 INFO: org.apache.tajo.master.TajoMaster (run(539)) - TajoMaster received SIGINT Signal 2015-08-21 19:14:57,662 INFO: org.apache.tajo.master.TajoMaster (run(540)) - ============================================ 2015-08-21 19:14:57,667 INFO: org.apache.tajo.session.SessionManager (removeSession(86)) - Session 316635e5-b4bd-4786-a15c-7944cab1bb43 is removed. 2015-08-21 19:14:57,668 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (Tajo-REST) listened on 0:0:0:0:0:0:0:0:16417) shutdown 2015-08-21 19:14:57,669 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped. 2015-08-21 19:14:57,669 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(178)) - Catalog Server (127.0.0.1:16414) shutdown 2015-08-21 19:14:57,670 INFO: org.mortbay.log (info(67)) - Shutdown hook executing 2015-08-21 19:14:57,671 INFO: org.mortbay.log (info(67)) - Shutdown hook complete 2015-08-21 19:14:57,673 INFO: org.apache.tajo.worker.TajoWorker (run(567)) - ============================================ 2015-08-21 19:14:57,673 INFO: org.apache.tajo.worker.TajoWorker (run(568)) - TajoWorker received SIGINT Signal 2015-08-21 19:14:57,673 INFO: org.apache.tajo.worker.TajoWorker (run(569)) - ============================================ eader initialized will read a total of 2 records. Aug 21, 2015 7:02:43 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:43 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 2 Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26 Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26 Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26 Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:57 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 26 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_orderkey] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 65B for [l_shipdate_function] BINARY: 1 values, 20B raw, 20B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records. Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records. Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records. Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 0 ms. row count = 1 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 0 ms. row count = 1 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records. Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 1 records. Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1 Aug 21, 2015 7:02:58 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 1 Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordWriter: Flushing mem columnStore to file. allocated memory: 212 Aug 21, 2015 7:03:01 PM 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} Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.ColumnChunkPageWriteStore: written 123B for [l_shipdate_function] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE] Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: reading another 1 footers Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.ParquetFileReader: Initiating action with parallelism: 5 Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 5 records. Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block Aug 21, 2015 7:03:01 PM INFO: org.apache.parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 5 2015-08-21 19:14:57,678 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (CatalogProtocol) listened on 127.0.0.1:16414) shutdown 2015-08-21 19:14:57,680 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_asf906.gq1.ygridcore.net_16418 stopped. 2015-08-21 19:14:57,680 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped 2015-08-21 19:14:57,681 INFO: org.apache.tajo.util.history.HistoryWriter (run(268)) - HistoryWriter_127.0.0.1_16416 stopped. 2015-08-21 19:14:57,684 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(111)) - NodeStatusUpdater stopped. 2015-08-21 19:14:57,685 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(262)) - Heartbeat Thread stopped. 2015-08-21 19:14:57,688 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:16420) shutdown 2015-08-21 19:14:57,688 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped 2015-08-21 19:14:57,688 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33628 is added to blk_1073741834_1010{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-52df8432-30ed-4935-b15c-399d06c34052:NORMAL:127.0.0.1:33628|RBW]]} size 524 2015-08-21 19:14:57,692 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(168)) - QueryMaster stopped 2015-08-21 19:14:57,690 INFO: org.apache.tajo.querymaster.QueryMaster (run(417)) - QueryMaster heartbeat thread stopped 2015-08-21 19:14:57,693 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(99)) - TajoWorkerClientService stopping 2015-08-21 19:14:57,693 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped 2015-08-21 19:14:57,695 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:16416) shutdown 2015-08-21 19:14:57,695 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:16415) shutdown 2015-08-21 19:14:57,695 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:16419) shutdown 2015-08-21 19:14:57,697 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(103)) - TajoWorkerClientService stopped 2015-08-21 19:14:57,700 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:16413) shutdown 2015-08-21 19:14:57,700 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(173)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:16418) shutdown 2015-08-21 19:14:57,700 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped 2015-08-21 19:14:57,700 INFO: org.apache.tajo.master.TajoMaster (serviceStop(406)) - Tajo Master main thread exiting 2015-08-21 19:14:57,701 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(377)) - TajoWorker main thread exiting 2015-08-21 19:14:57,713 WARN: org.apache.tajo.rpc.NettyClientBase (doReconnect(198)) - Exception [org.apache.tajo.ipc.TajoMasterClientProtocol(/127.0.0.1:16415)]: ClosedChannelException: Try to reconnect : /127.0.0.1:16415 2015-08-21 19:14:58,714 WARN: org.apache.tajo.rpc.NettyClientBase (doReconnect(198)) - Exception [org.apache.tajo.ipc.TajoMasterClientProtocol(/127.0.0.1:16415)]: ClosedChannelException: Try to reconnect : /127.0.0.1:16415 Results : Failed tests: TestDDLBuilder.testBuildDDLForExternalTable:64 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...> TestDDLBuilder.testBuildDDLForBaseTable:103 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]');> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]');> TestDDLBuilder.testBuildDDLQuotedTableName:90 expected:<...) USING TEXT WITH ('[compression.codec'='org.apache.hadoop.io.compress.GzipCodec', 'text.delimiter'='|]') PARTITION BY COLU...> but was:<...) USING TEXT WITH ('[text.delimiter'='|', 'compression.codec'='org.apache.hadoop.io.compress.GzipCodec]') PARTITION BY COLU...> Tests run: 1689, Failures: 3, Errors: 0, Skipped: 0 [INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Tajo Main ......................................... SUCCESS [ 2.003 s] [INFO] Tajo Project POM .................................. SUCCESS [ 2.535 s] [INFO] Tajo Maven Plugins ................................ SUCCESS [ 4.299 s] [INFO] Tajo Common ....................................... SUCCESS [ 23.228 s] [INFO] Tajo Algebra ...................................... SUCCESS [ 2.414 s] [INFO] Tajo Catalog Common ............................... SUCCESS [ 4.802 s] [INFO] Tajo Plan ......................................... SUCCESS [ 6.637 s] [INFO] Tajo Rpc Common ................................... SUCCESS [ 1.331 s] [INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 46.925 s] [INFO] Tajo Catalog Client ............................... SUCCESS [ 1.519 s] [INFO] Tajo Catalog Server ............................... SUCCESS [ 9.760 s] [INFO] Tajo Storage Common ............................... SUCCESS [ 8.593 s] [INFO] Tajo HDFS Storage ................................. SUCCESS [ 45.338 s] [INFO] Tajo PullServer ................................... SUCCESS [ 1.027 s] [INFO] Tajo Client ....................................... SUCCESS [ 2.542 s] [INFO] Tajo CLI tools .................................... SUCCESS [ 2.057 s] [INFO] ASM (thirdparty) .................................. SUCCESS [ 1.977 s] [INFO] Tajo RESTful Container ............................ SUCCESS [ 3.759 s] [INFO] Tajo Metrics ...................................... SUCCESS [ 1.436 s] [INFO] Tajo Core ......................................... SUCCESS [ 9.932 s] [INFO] Tajo RPC .......................................... SUCCESS [ 0.967 s] [INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 11.230 s] [INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.104 s] [INFO] Tajo Catalog ...................................... SUCCESS [ 1.031 s] [INFO] Tajo Client Example ............................... SUCCESS [ 1.045 s] [INFO] Tajo HBase Storage ................................ SUCCESS [ 3.796 s] [INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.354 s] [INFO] Tajo JDBC Driver .................................. SUCCESS [ 24.667 s] [INFO] Tajo Storage ...................................... SUCCESS [ 0.995 s] [INFO] Tajo Distribution ................................. SUCCESS [ 5.368 s] [INFO] Tajo Core Tests ................................... FAILURE [21:16 min] [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 25:10 min [INFO] Finished at: 2015-08-21T19:15:00+00:00 [INFO] Final Memory: 150M/2250M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: There are test failures. [ERROR] [ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-jdk8-nightly/ws/tajo-core-tests/target/surefire-reports> for the individual test results. [ERROR] -> [Help 1] [ERROR] [ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch. [ERROR] Re-run Maven using the -X switch to enable full debug logging. [ERROR] [ERROR] For more information about the errors and possible solutions, please read the following articles: [ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException [ERROR] [ERROR] After correcting the problems, you can resume the build with the command [ERROR] mvn <goals> -rf :tajo-core-tests Build step 'Execute shell' marked build as failure Archiving artifacts Sending artifact delta relative to Tajo-master-jdk8-nightly #82 Archived 1 artifacts Archive block size is 32768 Received 0 blocks and 58864764 bytes Compression is 0.0% Took 21 sec Recording test results
