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 2016/01/28 07:55:34 UTC
Build failed in Jenkins: Tajo-master-build #1068
See <https://builds.apache.org/job/Tajo-master-build/1068/changes>
Changes:
[jihoonson] TAJO-2036: Prevent out of memory in the master server, if the query
------------------------------------------
[...truncated 740927 lines...]
2016-01-28 06:55:29,247 INFO: org.apache.tajo.util.history.HistoryReader (getTaskHistory(325)) - Finding TaskHistory from 124,file:/tmp/1453964128217-0/20160128/tasks/127.0.0.1_28090/127.0.0.1_28090_06_0.hist
2016-01-28 06:55:29,247 INFO: org.apache.tajo.util.history.HistoryReader (getTaskHistory(325)) - Finding TaskHistory from 124,file:/tmp/1453964128217-0/20160128/tasks/127.0.0.1_28090/127.0.0.1_28090_06_0.hist
2016-01-28 06:55:29,248 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_28090 stopped.
2016-01-28 06:55:29,248 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:29,253 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(240)) - SQL: CREATE DATABASE IF NOT EXISTS "TestHistoryWriterReader"
2016-01-28 06:55:29,253 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:29,253 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - =============================================
2016-01-28 06:55:29,254 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:29,254 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - =============================================
2016-01-28 06:55:29,254 INFO: org.apache.tajo.master.exec.DDLExecutor (createDatabase(245)) - database "TestHistoryWriterReader" is already exists.
2016-01-28 06:55:29,257 INFO: org.apache.tajo.util.history.HistoryWriter (run(231)) - HistoryWriter_127.0.0.1_28090 started.
2016-01-28 06:55:29,257 INFO: org.apache.tajo.util.history.HistoryCleaner (run(62)) - History cleaner started: expiry day=7
2016-01-28 06:55:30,259 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(365)) - Saving query summary: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-detail/q_1453964129257_0001/query.hist
2016-01-28 06:55:30,268 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749131_8307{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 0
2016-01-28 06:55:30,269 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-detail/q_1453964129257_0001/eb_1453964129257_0001_000000.hist
2016-01-28 06:55:30,273 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749132_8308{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 0
2016-01-28 06:55:30,274 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-detail/q_1453964129257_0001/eb_1453964129257_0001_000001.hist
2016-01-28 06:55:30,277 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749133_8309{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 0
2016-01-28 06:55:30,279 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-detail/q_1453964129257_0001/eb_1453964129257_0001_000002.hist
2016-01-28 06:55:30,282 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749134_8310{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 0
2016-01-28 06:55:30,298 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_28090 stopped.
2016-01-28 06:55:30,298 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:30,301 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749132_8308 127.0.0.1:47185
2016-01-28 06:55:30,301 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749133_8309 127.0.0.1:47185
2016-01-28 06:55:30,302 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749134_8310 127.0.0.1:47185
2016-01-28 06:55:30,302 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749131_8307 127.0.0.1:47185
2016-01-28 06:55:30,303 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(240)) - SQL: CREATE DATABASE IF NOT EXISTS "TestHistoryWriterReader"
2016-01-28 06:55:30,304 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:30,304 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - =============================================
2016-01-28 06:55:30,304 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:30,304 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - =============================================
2016-01-28 06:55:30,305 INFO: org.apache.tajo.master.exec.DDLExecutor (createDatabase(245)) - database "TestHistoryWriterReader" is already exists.
2016-01-28 06:55:30,307 INFO: org.apache.tajo.util.history.HistoryWriter (run(231)) - HistoryWriter_127.0.0.1_28090 started.
2016-01-28 06:55:30,307 INFO: org.apache.tajo.util.history.HistoryCleaner (run(62)) - History cleaner started: expiry day=7
2016-01-28 06:55:30,378 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:47185 to delete [blk_1073749120_8296, blk_1073749121_8297, blk_1073749125_8301, blk_1073749131_8307, blk_1073749132_8308, blk_1073749133_8309, blk_1073749134_8310, blk_1073749119_8295]
2016-01-28 06:55:31,310 INFO: org.apache.tajo.util.history.HistoryWriter (rollingQuerySummaryWriter(432)) - Create query history file: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-list/query-list-065531.hist
2016-01-28 06:55:31,432 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_28090 stopped.
2016-01-28 06:55:31,436 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749135_8311{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 397
2016-01-28 06:55:31,837 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:31,839 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749135_8311 127.0.0.1:47185
2016-01-28 06:55:31,840 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(240)) - SQL: CREATE DATABASE IF NOT EXISTS "TestHistoryWriterReader"
2016-01-28 06:55:31,840 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:31,841 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - =============================================
2016-01-28 06:55:31,841 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
CREATE_DATABASE(0) IF NOT EXISTS TestHistoryWriterReader
2016-01-28 06:55:31,841 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - =============================================
2016-01-28 06:55:31,841 INFO: org.apache.tajo.master.exec.DDLExecutor (createDatabase(245)) - database "TestHistoryWriterReader" is already exists.
2016-01-28 06:55:31,843 INFO: org.apache.tajo.util.history.HistoryWriter (run(231)) - HistoryWriter_127.0.0.1_28090 started.
2016-01-28 06:55:31,844 INFO: org.apache.tajo.util.history.HistoryCleaner (run(62)) - History cleaner started: expiry day=7
2016-01-28 06:55:32,845 INFO: org.apache.tajo.util.history.HistoryWriter (rollingQuerySummaryWriter(432)) - Create query history file: hdfs://localhost:58035/tmp/tajo-test-history/20160128/query-list/query-list-065532.hist
2016-01-28 06:55:32,972 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_28090 stopped.
2016-01-28 06:55:32,975 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749136_8312{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 2000
2016-01-28 06:55:33,376 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:33,378 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749136_8312 127.0.0.1:47185
2016-01-28 06:55:33,379 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:47185 to delete [blk_1073749136_8312, blk_1073749135_8311]
2016-01-28 06:55:33,385 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session a74f09d8-9830-40b0-a26f-3fa03c22abc3 is removed.
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.18 sec - in org.apache.tajo.util.history.TestHistoryWriterReader
Running org.apache.tajo.util.TestRpcParamFactory
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.031 sec - in org.apache.tajo.util.TestRpcParamFactory
Running org.apache.tajo.util.TestJSPUtil
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec - in org.apache.tajo.util.TestJSPUtil
Running org.apache.tajo.TestTajoIds
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.TestTajoIds
Running org.apache.tajo.storage.TestFileFragment
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.092 sec - in org.apache.tajo.storage.TestFileFragment
Running org.apache.tajo.storage.TestRowFile
2016-01-28 06:55:33,546 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073749137_8313{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 0
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.037 sec - in org.apache.tajo.storage.TestRowFile
Running org.apache.tajo.resource.TestResources
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.resource.TestResources
2016-01-28 06:55:33,578 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
2016-01-28 06:55:33,578 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
Jan 28, 2016 6:49:17 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:18 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:29 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:29 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:29 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:29 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:29 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jan 28, 2016 6:49:32 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
2016-01-28 06:55:33,588 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session dff9c457-507b-403c-9287-6eed901d6ca2 is removed.
2016-01-28 06:55:33,591 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session cd7c314c-a56e-458d-836c-66492d51e364 is removed.
2016-01-28 06:55:33,594 INFO: org.apache.tajo.worker.TajoWorker (run(518)) - ============================================
2016-01-28 06:55:33,594 INFO: org.apache.tajo.worker.TajoWorker (run(519)) - TajoWorker received SIGINT Signal
2016-01-28 06:55:33,595 INFO: org.apache.tajo.worker.TajoWorker (run(520)) - ============================================
2016-01-28 06:55:33,601 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:33,601 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf905.gq1.ygridcore.net_18653 stopped.
2016-01-28 06:55:33,630 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(261)) - Heartbeat Thread stopped.
2016-01-28 06:55:33,631 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(113)) - NodeStatusUpdater stopped.
2016-01-28 06:55:33,632 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:18655) shutdown
2016-01-28 06:55:33,634 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2016-01-28 06:55:33,634 INFO: org.apache.tajo.querymaster.QueryMaster (run(432)) - QueryMaster heartbeat thread stopped
2016-01-28 06:55:33,635 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(164)) - QueryMaster stopped
2016-01-28 06:55:33,635 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2016-01-28 06:55:33,635 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:18654) shutdown
2016-01-28 06:55:33,635 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2016-01-28 06:55:33,635 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:18653) shutdown
2016-01-28 06:55:33,635 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2016-01-28 06:55:33,636 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(332)) - TajoWorker main thread exiting
2016-01-28 06:55:35,840 INFO: org.apache.tajo.master.TajoMaster (run(568)) - ============================================
2016-01-28 06:55:35,841 INFO: org.apache.tajo.master.TajoMaster (run(569)) - TajoMaster received SIGINT Signal
2016-01-28 06:55:35,842 INFO: org.apache.tajo.master.TajoMaster (run(570)) - ============================================
2016-01-28 06:55:35,842 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (Tajo-REST) listened on 127.0.0.1:18652) shutdown
2016-01-28 06:55:35,842 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2016-01-28 06:55:35,849 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_18651 stopped.
2016-01-28 06:55:35,854 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47185 is added to blk_1073741839_1015{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-3df7f2d5-7afc-473f-83d8-ea3c4ea86dc3:NORMAL:127.0.0.1:47185|RBW]]} size 700
2016-01-28 06:55:35,855 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:18651) shutdown
2016-01-28 06:55:35,855 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 06:55:37,961 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:18650) shutdown
2016-01-28 06:55:37,962 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(182)) - Catalog Server (127.0.0.1:18649) shutdown
2016-01-28 06:55:37,962 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (CatalogProtocol) listened on 127.0.0.1:18649) shutdown
2016-01-28 06:55:37,963 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2978)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/7904d2fd-73ca-4ab9-8962-8afac7c21cab/db;create=true)>
2016-01-28 06:55:37,964 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:18648) shutdown
2016-01-28 06:55:37,965 INFO: org.apache.tajo.master.TajoMaster (serviceStop(424)) - Tajo Master main thread exiting
2016-01-28 06:55:38,016 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(68)) - Derby shutdown complete normally.
2016-01-28 06:55:38,016 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(75)) - Shutdown database
Results :
Tests in error:
TestJoinOnPartitionedTables.testPartialFilterPushDown:95->QueryTestCaseBase.runSimpleTests:622 » UndefinedTable
Tests run: 1734, Failures: 0, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.957 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.671 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 4.200 s]
[INFO] Tajo Common ....................................... SUCCESS [ 29.495 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.938 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.556 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 7.824 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.373 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [02:24 min]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.572 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [01:02 min]
[INFO] Tajo Storage Common ............................... SUCCESS [ 3.356 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [01:04 min]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.090 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.566 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 2.261 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 4.181 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.098 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 4.453 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.788 s]
[INFO] Tajo Core ......................................... SUCCESS [ 7.585 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.975 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 27.647 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.107 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.987 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.090 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 4.559 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.916 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 35.911 s]
[INFO] Tajo JDBC storage common .......................... SUCCESS [ 0.896 s]
[INFO] Tajo PostgreSQL JDBC storage ...................... SUCCESS [ 1.293 s]
[INFO] Tajo S3 storage ................................... SUCCESS [ 0.235 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 1.007 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.513 s]
[INFO] Tajo Core Tests ................................... FAILURE [20:44 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 28:06 min
[INFO] Finished at: 2016-01-28T06:55:38+00:00
[INFO] Final Memory: 150M/1339M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Updating TAJO-2036
Jenkins build is back to normal : Tajo-master-build #1071
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/1071/changes>
Build failed in Jenkins: Tajo-master-build #1070
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/1070/>
------------------------------------------
[...truncated 739622 lines...]
2016-01-28 08:58:38,571 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (QueryCoordinatorProtocol) listens on /127.0.0.1:59597
2016-01-28 08:58:38,571 INFO: org.apache.tajo.master.QueryCoordinatorService (serviceStart(70)) - Instantiated TajoMasterService at localhost/127.0.0.1:59597
2016-01-28 08:58:38,572 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (Tajo-REST) listens on /127.0.0.1:34499
2016-01-28 08:58:38,572 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStart(118)) - Tajo Rest Service started.
2016-01-28 08:58:38,574 WARN: org.apache.tajo.util.metrics.TajoSystemMetrics (setMetricsReporter(140)) - No property MASTER.reporters in tajo-metrics.properties
2016-01-28 08:58:38,575 WARN: org.apache.tajo.util.metrics.TajoSystemMetrics (setMetricsReporter(140)) - No property MASTER-JVM.reporters in tajo-metrics.properties
2016-01-28 08:58:38,579 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073741825_1001 127.0.0.1:55568
2016-01-28 08:58:38,589 INFO: org.apache.tajo.ha.HdfsServiceTracker (initSystemDirectory(91)) - System HA dir 'hdfs://localhost:33678/tajo/system/ha' is created
2016-01-28 08:58:38,590 INFO: org.apache.tajo.ha.HdfsServiceTracker (initSystemDirectory(97)) - System HA Active dir 'hdfs://localhost:33678/tajo/system/ha/active' is created
2016-01-28 08:58:38,591 INFO: org.apache.tajo.ha.HdfsServiceTracker (initSystemDirectory(103)) - System HA Backup dir 'hdfs://localhost:33678/tajo/system/ha/backup' is created
2016-01-28 08:58:38,598 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073749133_8309{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 0
2016-01-28 08:58:38,618 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073749134_8310{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 0
2016-01-28 08:58:38,620 INFO: org.apache.tajo.ha.HdfsServiceTracker (register(156)) - This is added to active master (127.0.0.1:59597)
2016-01-28 08:58:38,621 INFO: org.apache.tajo.util.history.HistoryWriter (run(231)) - HistoryWriter_127.0.0.1_59597 started.
2016-01-28 08:58:38,621 INFO: org.apache.tajo.util.history.HistoryCleaner (run(62)) - History cleaner started: expiry day=7
2016-01-28 08:58:38,621 INFO: org.apache.tajo.master.TajoMaster (checkAndInitializeSystemDirectories(245)) - Tajo Root Directory: hdfs://localhost:33678/tajo
2016-01-28 08:58:38,621 INFO: org.apache.tajo.master.TajoMaster (checkAndInitializeSystemDirectories(250)) - FileSystem (hdfs://localhost:33678) is initialized.
2016-01-28 08:58:38,623 INFO: org.apache.tajo.master.TajoMaster (checkAndInitializeSystemDirectories(270)) - Tajo Warehouse dir: hdfs://localhost:33678/tajo/warehouse
2016-01-28 08:58:38,623 INFO: org.apache.tajo.master.TajoMaster (checkAndInitializeSystemDirectories(279)) - Staging dir: hdfs://localhost:33678/tajo/warehouse
2016-01-28 08:58:39,105 INFO: org.apache.tajo.master.rm.TajoResourceManager (serviceInit(97)) - Loaded resource scheduler : class org.apache.tajo.master.scheduler.SimpleScheduler
2016-01-28 08:58:39,106 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (TajoResourceTrackerProtocol) listens on /127.0.0.1:44008
2016-01-28 08:58:39,107 INFO: org.apache.tajo.master.rm.TajoResourceTracker (serviceInit(99)) - TajoResourceTracker starts up (localhost/127.0.0.1:44008)
2016-01-28 08:58:39,107 INFO: org.apache.tajo.catalog.CatalogServer (serviceInit(125)) - Catalog Store Class: org.apache.tajo.catalog.store.DerbyStore
2016-01-28 08:58:39,107 INFO: org.apache.tajo.catalog.store.DerbyStore (<init>(155)) - Loaded the Catalog driver (org.apache.derby.jdbc.EmbeddedDriver)
2016-01-28 08:58:39,107 INFO: org.apache.tajo.catalog.store.DerbyStore (<init>(161)) - Trying to connect database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/906174e6-1091-474d-9fa9-8b76e7e509c9/db;create=true)>
2016-01-28 08:58:39,107 INFO: org.apache.tajo.catalog.store.DerbyStore (<init>(163)) - Connected to database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/906174e6-1091-474d-9fa9-8b76e7e509c9/db;create=true)>
2016-01-28 08:58:39,113 INFO: org.apache.tajo.catalog.store.DerbyStore (<init>(175)) - The meta table of CatalogServer already is created.
2016-01-28 08:58:39,114 INFO: org.apache.tajo.catalog.store.DerbyStore (verifySchemaVersion(279)) - The compatibility of the catalog schema (version: 12) has been verified.
Jan 28, 2016 8:58:39 AM org.glassfish.jersey.server.ApplicationHandler initialize
INFO: Initiating Jersey application, version Jersey: 2.6 2014-02-18 21:52:53...
2016-01-28 08:58:39,175 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceInit(109)) - Tajo Rest Service initialized.
2016-01-28 08:58:39,175 INFO: org.apache.tajo.master.TajoMaster (serviceInit(215)) - Tajo Master is initialized.
2016-01-28 08:58:39,175 INFO: org.apache.tajo.master.TajoMaster (serviceStart(307)) - TajoMaster is starting up
2016-01-28 08:58:39,176 INFO: org.apache.tajo.master.TajoMaster (checkBaseTBSpaceAndDatabase(407)) - Default database (default) is already prepared.
2016-01-28 08:58:39,179 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (CatalogProtocol) listens on /127.0.0.1:53419
2016-01-28 08:58:39,180 INFO: org.apache.tajo.catalog.CatalogServer (serviceStart(176)) - Catalog Server startup (127.0.0.1:53419)
2016-01-28 08:58:39,182 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (TajoMasterClientProtocol) listens on /127.0.0.1:44024
2016-01-28 08:58:39,182 INFO: org.apache.tajo.master.TajoMasterClientService (serviceStart(104)) - Instantiated TajoMasterClientService at localhost/127.0.0.1:44024
2016-01-28 08:58:39,183 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (QueryCoordinatorProtocol) listens on /127.0.0.1:55074
2016-01-28 08:58:39,183 INFO: org.apache.tajo.master.QueryCoordinatorService (serviceStart(70)) - Instantiated TajoMasterService at localhost/127.0.0.1:55074
2016-01-28 08:58:39,183 INFO: org.apache.tajo.rpc.NettyServerBase (start(129)) - Rpc (Tajo-REST) listens on /127.0.0.1:41491
2016-01-28 08:58:39,184 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStart(118)) - Tajo Rest Service started.
2016-01-28 08:58:39,185 WARN: org.apache.tajo.util.metrics.TajoSystemMetrics (setMetricsReporter(140)) - No property MASTER.reporters in tajo-metrics.properties
2016-01-28 08:58:39,189 WARN: org.apache.tajo.util.metrics.TajoSystemMetrics (setMetricsReporter(140)) - No property MASTER-JVM.reporters in tajo-metrics.properties
2016-01-28 08:58:39,193 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749134_8310 127.0.0.1:55568
2016-01-28 08:58:39,196 WARN: org.apache.hadoop.hdfs.StateChange (startFileInternal(2602)) - DIR* NameSystem.startFile: /tajo/system/ha/active/active.lock /tajo/system/ha/active/active.lock for client 127.0.0.1 already exists
2016-01-28 08:58:39,205 INFO: org.apache.tajo.ha.HdfsServiceTracker (createLockFile(224)) - Lock file already exists at (hdfs://localhost:33678/tajo/system/ha/active/active.lock)
2016-01-28 08:58:39,212 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073749135_8311{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 0
2016-01-28 08:58:39,213 INFO: org.apache.tajo.ha.HdfsServiceTracker (register(187)) - This is added to backup master (127.0.0.1:55074)
2016-01-28 08:58:39,214 INFO: org.apache.tajo.util.history.HistoryWriter (run(231)) - HistoryWriter_127.0.0.1_55074 started.
2016-01-28 08:58:39,214 INFO: org.apache.tajo.util.history.HistoryCleaner (run(62)) - History cleaner started: expiry day=7
2016-01-28 08:58:39,227 INFO: org.apache.tajo.session.SessionManager (createSession(79)) - Session 70eaa9a0-7982-4301-b7d2-c8a3a4258df1 is created.
2016-01-28 08:58:39,228 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(177)) - Query: CREATE TABLE default.ha_test1 (age int);
2016-01-28 08:58:39,229 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2016-01-28 08:58:39,229 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - =============================================
2016-01-28 08:58:39,230 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2016-01-28 08:58:39,230 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - =============================================
2016-01-28 08:58:39,233 INFO: org.apache.tajo.catalog.CatalogServer (createTable(688)) - relation "default.ha_test1" is added to the catalog (127.0.0.1:48240)
2016-01-28 08:58:39,234 INFO: org.apache.tajo.master.exec.DDLExecutor (create(112)) - relation 'default.ha_test1' created.
2016-01-28 08:58:39,234 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(177)) - Query: CREATE TABLE default.ha_test2 (age int);
2016-01-28 08:58:39,234 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(281)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2016-01-28 08:58:39,235 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - =============================================
2016-01-28 08:58:39,235 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
2016-01-28 08:58:39,235 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(285)) - =============================================
2016-01-28 08:58:39,239 INFO: org.apache.tajo.catalog.CatalogServer (createTable(688)) - relation "default.ha_test2" is added to the catalog (127.0.0.1:48240)
2016-01-28 08:58:39,239 INFO: org.apache.tajo.master.exec.DDLExecutor (create(112)) - relation 'default.ha_test2' created.
2016-01-28 08:58:39,239 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 70eaa9a0-7982-4301-b7d2-c8a3a4258df1 is removed.
2016-01-28 08:58:39,242 INFO: org.apache.tajo.session.SessionManager (createSession(79)) - Session 52f83a6c-af02-4785-90b4-ad23234b92dc is created.
2016-01-28 08:58:39,244 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 52f83a6c-af02-4785-90b4-ad23234b92dc is removed.
2016-01-28 08:58:39,246 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749133_8309 127.0.0.1:55568
2016-01-28 08:58:39,248 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (Tajo-REST) listened on 127.0.0.1:34499) shutdown
2016-01-28 08:58:39,248 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2016-01-28 08:58:39,250 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:59597) shutdown
2016-01-28 08:58:39,250 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_59597 stopped.
2016-01-28 08:58:39,250 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 08:58:40,221 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749135_8311 127.0.0.1:55568
2016-01-28 08:58:40,226 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073749136_8312{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 81
2016-01-28 08:58:40,644 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073749137_8313{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 0
2016-01-28 08:58:40,647 INFO: org.apache.tajo.ha.HdfsServiceTracker (register(156)) - This is added to active master (127.0.0.1:55074)
2016-01-28 08:58:41,387 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:55568 to delete [blk_1073741825_1001, blk_1073749133_8309, blk_1073749134_8310, blk_1073749135_8311]
2016-01-28 08:58:41,453 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:48563) shutdown
2016-01-28 08:58:41,453 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(182)) - Catalog Server (127.0.0.1:48240) shutdown
2016-01-28 08:58:41,453 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (CatalogProtocol) listened on 127.0.0.1:48240) shutdown
2016-01-28 08:58:41,455 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2978)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/906174e6-1091-474d-9fa9-8b76e7e509c9/db;create=true)>
2016-01-28 08:58:41,455 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:53586) shutdown
2016-01-28 08:58:41,456 INFO: org.apache.tajo.master.TajoMaster (serviceStop(424)) - Tajo Master main thread exiting
2016-01-28 08:58:41,463 INFO: org.apache.tajo.session.SessionManager (createSession(79)) - Session a09bfefb-29b6-40ec-839f-b2fd6b9f3edc is created.
2016-01-28 08:58:41,466 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session a09bfefb-29b6-40ec-839f-b2fd6b9f3edc is removed.
2016-01-28 08:58:41,470 INFO: BlockStateChange (addToInvalidates(1106)) - BLOCK* addToInvalidates: blk_1073749136_8312 127.0.0.1:55568
2016-01-28 08:58:41,472 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (Tajo-REST) listened on 127.0.0.1:41491) shutdown
2016-01-28 08:58:41,472 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2016-01-28 08:58:41,473 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 08:58:41,473 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_55074 stopped.
2016-01-28 08:58:41,476 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:55074) shutdown
2016-01-28 08:58:43,678 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:44024) shutdown
2016-01-28 08:58:43,679 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(182)) - Catalog Server (127.0.0.1:53419) shutdown
2016-01-28 08:58:43,679 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (CatalogProtocol) listened on 127.0.0.1:53419) shutdown
2016-01-28 08:58:43,680 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2978)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/906174e6-1091-474d-9fa9-8b76e7e509c9/db;create=true)>
2016-01-28 08:58:43,680 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:44008) shutdown
2016-01-28 08:58:43,680 INFO: org.apache.tajo.master.TajoMaster (serviceStop(424)) - Tajo Master main thread exiting
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.684 sec - in org.apache.tajo.ha.TestHAServiceHDFSImpl
Running org.apache.tajo.TestTajoIds
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.TestTajoIds
2016-01-28 08:58:43,690 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
2016-01-28 08:58:43,690 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
2016-01-28 08:58:43,700 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 28ae5974-f56d-4f3c-9781-32157db44f73 is removed.
2016-01-28 08:58:43,705 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 9b9a0043-32ce-47ad-b89c-4ac72a3ac808 is removed.
2016-01-28 08:58:43,707 INFO: org.apache.tajo.worker.TajoWorker (run(518)) - ============================================
2016-01-28 08:58:43,707 INFO: org.apache.tajo.worker.TajoWorker (run(519)) - TajoWorker received SIGINT Signal
2016-01-28 08:58:43,707 INFO: org.apache.tajo.worker.TajoWorker (run(520)) - ============================================
2016-01-28 08:58:43,709 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf907.gq1.ygridcore.net_42684 stopped.
2016-01-28 08:58:43,710 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 08:58:43,742 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(113)) - NodeStatusUpdater stopped.
2016-01-28 08:58:43,742 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(261)) - Heartbeat Thread stopped.
2016-01-28 08:58:43,742 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:42686) shutdown
2016-01-28 08:58:43,745 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2016-01-28 08:58:43,745 INFO: org.apache.tajo.querymaster.QueryMaster (run(432)) - QueryMaster heartbeat thread stopped
2016-01-28 08:58:43,746 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(164)) - QueryMaster stopped
2016-01-28 08:58:43,746 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2016-01-28 08:58:43,746 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:42685) shutdown
2016-01-28 08:58:43,746 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2016-01-28 08:58:43,747 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:42684) shutdown
2016-01-28 08:58:43,747 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2016-01-28 08:58:43,747 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(332)) - TajoWorker main thread exiting
2016-01-28 08:58:44,387 INFO: BlockStateChange (invalidateWorkForOneNode(3488)) - BLOCK* BlockManager: ask 127.0.0.1:55568 to delete [blk_1073749136_8312]
2016-01-28 08:58:45,953 INFO: org.apache.tajo.master.TajoMaster (run(568)) - ============================================
2016-01-28 08:58:45,954 INFO: org.apache.tajo.master.TajoMaster (run(569)) - TajoMaster received SIGINT Signal
2016-01-28 08:58:45,954 INFO: org.apache.tajo.master.TajoMaster (run(570)) - ============================================
2016-01-28 08:58:45,955 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (Tajo-REST) listened on 127.0.0.1:42683) shutdown
2016-01-28 08:58:45,955 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2016-01-28 08:58:45,961 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_42682 stopped.
2016-01-28 08:58:45,963 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:55568 is added to blk_1073741834_1010{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-93ab4938-430e-4765-bcab-d6e743be2736:NORMAL:127.0.0.1:55568|RBW]]} size 524
2016-01-28 08:58:45,963 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:42682) shutdown
2016-01-28 08:58:45,964 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 08:58:48,067 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:42681) shutdown
2016-01-28 08:58:48,068 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(182)) - Catalog Server (127.0.0.1:42680) shutdown
2016-01-28 08:58:48,068 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (CatalogProtocol) listened on 127.0.0.1:42680) shutdown
2016-01-28 08:58:48,068 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2978)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/906174e6-1091-474d-9fa9-8b76e7e509c9/db;create=true)>
2016-01-28 08:58:48,069 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:42679) shutdown
2016-01-28 08:58:48,070 INFO: org.apache.tajo.master.TajoMaster (serviceStop(424)) - Tajo Master main thread exiting
2016-01-28 08:58:48,129 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(68)) - Derby shutdown complete normally.
2016-01-28 08:58:48,129 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(75)) - Shutdown database
Results :
Tests in error:
TestJoinOnPartitionedTables.testPartialFilterPushDown:95->QueryTestCaseBase.runSimpleTests:622 » UndefinedTable
Tests run: 1734, Failures: 0, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.624 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.537 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.972 s]
[INFO] Tajo Common ....................................... SUCCESS [ 30.748 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.763 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.270 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 7.156 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.202 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [02:26 min]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.389 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 10.613 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 2.972 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 57.245 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 0.860 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.633 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.960 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 3.694 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 1.825 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.747 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.714 s]
[INFO] Tajo Core ......................................... SUCCESS [ 6.711 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.924 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 9.515 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.078 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.973 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.037 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.672 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.738 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 33.388 s]
[INFO] Tajo JDBC storage common .......................... SUCCESS [ 0.838 s]
[INFO] Tajo PostgreSQL JDBC storage ...................... SUCCESS [ 0.824 s]
[INFO] Tajo S3 storage ................................... SUCCESS [ 0.276 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.976 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.317 s]
[INFO] Tajo Core Tests ................................... FAILURE [21:44 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 27:40 min
[INFO] Finished at: 2016-01-28T08:58:48+00:00
[INFO] Final Memory: 151M/1975M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Tajo-master-build #1069
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/1069/changes>
Changes:
[jhkim] TAJO-2065: Increase default heap size.
[jhkim] TAJO-2065: Increase default heap size (missing change).
------------------------------------------
[...truncated 739738 lines...]
[Outgoing]
[q_1453966428708_2257] 1 => 2 (type=HASH_SHUFFLE, key=default.lineitem.l_orderkey (INT4), num=32)
GROUP_BY(5)(l_orderkey)
=> target list: default.lineitem.l_orderkey (INT4)
=> out schema:{(1) default.lineitem.l_orderkey (INT4)}
=> in schema:{(1) default.lineitem.l_orderkey (INT4)}
SCAN(0) on default.lineitem
=> target list: default.lineitem.l_orderkey (INT4)
=> out schema: {(1) default.lineitem.l_orderkey (INT4)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4), default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4), default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount (FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag (TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate (TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate (TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode (TEXT), default.lineitem.l_comment (TEXT)}
=======================================================
Block Id: eb_1453966428708_2257_000002 [ROOT]
=======================================================
[Incoming]
[q_1453966428708_2257] 1 => 2 (type=HASH_SHUFFLE, key=default.lineitem.l_orderkey (INT4), num=32)
GROUP_BY(1)(l_orderkey)
=> target list: default.lineitem.l_orderkey (INT4)
=> out schema:{(1) default.lineitem.l_orderkey (INT4)}
=> in schema:{(1) default.lineitem.l_orderkey (INT4)}
SCAN(6) on eb_1453966428708_2257_000001
=> out schema: {(1) default.lineitem.l_orderkey (INT4)}
=> in schema: {(1) default.lineitem.l_orderkey (INT4)}
=======================================================
Block Id: eb_1453966428708_2257_000003 [TERMINAL]
=======================================================
2016-01-28 07:56:23,583 INFO: org.apache.tajo.querymaster.Query (<init>(236)) -
=======================================================
The order of execution:
1: eb_1453966428708_2257_000001
2: eb_1453966428708_2257_000002
3: eb_1453966428708_2257_000003
=======================================================
2016-01-28 07:56:23,585 INFO: org.apache.tajo.querymaster.Query (handle(878)) - Processing q_1453966428708_2257 of type START
2016-01-28 07:56:23,586 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (first(84)) - Initial executable blocks [eb_1453966428708_2257_000001]
2016-01-28 07:56:23,586 INFO: org.apache.tajo.querymaster.Query (handle(896)) - q_1453966428708_2257 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2016-01-28 07:56:23,586 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1032)) - eb_1453966428708_2257_000001, Table's volume is approximately 725 MB
2016-01-28 07:56:23,586 INFO: org.apache.tajo.querymaster.Stage (calculateShuffleOutputNum(1036)) - eb_1453966428708_2257_000001, The determined number of aggregation partitions is 3
2016-01-28 07:56:23,586 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(915)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1453966428708_2257_000001
2016-01-28 07:56:23,589 INFO: org.apache.tajo.storage.FileTablespace (listStatus(346)) - Total input paths to process : 1
2016-01-28 07:56:23,590 INFO: org.apache.tajo.storage.FileTablespace (getSplits(547)) - Total # of splits: 1
2016-01-28 07:56:23,591 INFO: org.apache.tajo.querymaster.Stage (run(867)) - 1 objects are scheduled
2016-01-28 07:56:23,591 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(135)) - Start TaskScheduler
2016-01-28 07:56:23,592 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (increaseConcurrency(526)) - Assigned host : 127.0.0.1, Unknown Volume : -1, Concurrency : 1
2016-01-28 07:56:23,593 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf901.gq1.ygridcore.net:49987
2016-01-28 07:56:23,593 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (assignToLeafTasks(922)) - Assigned Local/Rack/Total: (0/1/1), Attempted Cancel/Assign/Total: (0/1/1), Locality: 0.00%, Rack host: asf901.gq1.ygridcore.net
2016-01-28 07:56:23,597 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(128)) - Tajo Root Dir: hdfs://localhost:38781/tajo
2016-01-28 07:56:23,597 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(129)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/8aeee890-8aa1-40b2-94c3-360073d24cf2/tajo-localdir>
2016-01-28 07:56:23,598 INFO: org.apache.tajo.worker.TaskManager (handle(181)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:500, Disks:5, vCores:2)
2016-01-28 07:56:23,600 INFO: org.apache.tajo.worker.TaskImpl (initPlan(159)) - * Task ta_1453966428708_2257_000001_000000_00 is initialized. InterQuery: true, Shuffle: HASH_SHUFFLE, Fragments: 1, Fetches:0, Local dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/8aeee890-8aa1-40b2-94c3-360073d24cf2/tajo-localdir/q_1453966428708_2257/output/1/0_0>
2016-01-28 07:56:23,600 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1029)) - Aggregation:estimatedSize=604, threshold=67108864
2016-01-28 07:56:23,600 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1031)) - The planner chooses [Hash Aggregation]
2016-01-28 07:56:23,600 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createInMemoryHashAggregation(973)) - The planner chooses [Hash Aggregation]
2016-01-28 07:56:23,605 INFO: org.apache.tajo.worker.TaskImpl (run(469)) - ta_1453966428708_2257_000001_000000_00 is complete. 5 ms elapsed, final state:TA_SUCCEEDED
2016-01-28 07:56:23,606 INFO: org.apache.tajo.querymaster.Stage (transition(1365)) - Stage - eb_1453966428708_2257_000001 finalize HASH_SHUFFLE (total=1, success=1, killed=0)
2016-01-28 07:56:23,606 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(164)) - Task Scheduler stopped
2016-01-28 07:56:23,606 INFO: org.apache.tajo.querymaster.Stage (transition(1376)) - eb_1453966428708_2257_000001, wait for HASH_SHUFFLE reports. expected Tasks:1
2016-01-28 07:56:23,607 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(127)) - TaskScheduler schedulingThread stopped
2016-01-28 07:56:23,607 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(182)) - Close HashShuffleAppenderWrapper:eb_1453966428708_2257_000001, intermediates=2
2016-01-28 07:56:23,607 INFO: org.apache.tajo.querymaster.Stage (finalizeShuffleReport(1322)) - eb_1453966428708_2257_000001, Finalized HASH_SHUFFLE reports: 1
2016-01-28 07:56:23,608 INFO: org.apache.tajo.querymaster.Stage (transition(1423)) - Stage completed - eb_1453966428708_2257_000001 (total=1, success=1, killed=0)
2016-01-28 07:56:23,608 INFO: org.apache.tajo.querymaster.Query (handle(878)) - Processing q_1453966428708_2257 of type STAGE_COMPLETED
2016-01-28 07:56:23,608 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1453966428708_2257_000002
2016-01-28 07:56:23,608 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(778)) - Scheduling Stage:eb_1453966428708_2257_000002
2016-01-28 07:56:23,608 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(915)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1453966428708_2257_000002
2016-01-28 07:56:23,608 INFO: org.apache.tajo.worker.ExecutionBlockContext (stop(176)) - Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2016-01-28 07:56:23,609 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1109)) - eb_1453966428708_2257_000002, Table's volume is approximately 1 MB
2016-01-28 07:56:23,609 INFO: org.apache.tajo.querymaster.Stage (getNonLeafTaskNum(1114)) - eb_1453966428708_2257_000002, The determined number of non-leaf tasks is 1
2016-01-28 07:56:23,609 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleHashShuffledFetches(886)) - eb_1453966428708_2257_000002, ScheduleHashShuffledFetches - Max num=1, finalFetchURI=2
2016-01-28 07:56:23,610 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleHashShuffledFetches(906)) - eb_1453966428708_2257_000002, DeterminedTaskNum : 1
2016-01-28 07:56:23,610 INFO: org.apache.tajo.querymaster.Stage (run(867)) - 1 objects are scheduled
2016-01-28 07:56:23,610 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(135)) - Start TaskScheduler
2016-01-28 07:56:23,610 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(160)) - Stopped execution block:eb_1453966428708_2257_000001
2016-01-28 07:56:23,626 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf901.gq1.ygridcore.net:49987
2016-01-28 07:56:23,628 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(128)) - Tajo Root Dir: hdfs://localhost:38781/tajo
2016-01-28 07:56:23,628 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(129)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/8aeee890-8aa1-40b2-94c3-360073d24cf2/tajo-localdir>
2016-01-28 07:56:23,632 INFO: org.apache.tajo.worker.TaskManager (handle(181)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:500, Disks:6, vCores:2)
2016-01-28 07:56:23,632 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(274)) - Output File Path: hdfs://localhost:38781/tmp/tajo-jenkins/staging/q_1453966428708_2257/RESULT/part-02-000000-000
2016-01-28 07:56:23,632 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - Output File Path: hdfs://localhost:38781/tmp/tajo-jenkins/staging/q_1453966428708_2257/RESULT/part-02-000000-000
2016-01-28 07:56:23,632 INFO: org.apache.tajo.worker.TaskImpl (initPlan(159)) - * Task ta_1453966428708_2257_000002_000000_00 is initialized. InterQuery: false, Shuffle: null, Fragments: 1, Fetches:2, Local dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/8aeee890-8aa1-40b2-94c3-360073d24cf2/tajo-localdir/q_1453966428708_2257/output/2/0_0>
2016-01-28 07:56:23,635 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(740)) - Create shuffle Fetchers local:2, remote:0
2016-01-28 07:56:23,635 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(380)) - ta_1453966428708_2257_000002_000000_00 All fetches are done!
2016-01-28 07:56:23,636 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1029)) - Aggregation:estimatedSize=24, threshold=67108864
2016-01-28 07:56:23,636 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createBestAggregationPlan(1031)) - The planner chooses [Hash Aggregation]
2016-01-28 07:56:23,636 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createInMemoryHashAggregation(973)) - The planner chooses [Hash Aggregation]
2016-01-28 07:56:23,641 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749123_8299{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 0
2016-01-28 07:56:23,642 INFO: org.apache.tajo.worker.TaskImpl (run(469)) - ta_1453966428708_2257_000002_000000_00 is complete. 7 ms elapsed, final state:TA_SUCCEEDED
2016-01-28 07:56:23,642 INFO: org.apache.tajo.querymaster.Stage (transition(1365)) - Stage - eb_1453966428708_2257_000002 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2016-01-28 07:56:23,642 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(164)) - Task Scheduler stopped
2016-01-28 07:56:23,643 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(127)) - TaskScheduler schedulingThread stopped
2016-01-28 07:56:23,643 INFO: org.apache.tajo.querymaster.Stage (transition(1423)) - Stage completed - eb_1453966428708_2257_000002 (total=1, success=1, killed=0)
2016-01-28 07:56:23,643 INFO: org.apache.tajo.querymaster.Query (handle(878)) - Processing q_1453966428708_2257 of type STAGE_COMPLETED
2016-01-28 07:56:23,643 INFO: org.apache.tajo.worker.ExecutionBlockContext (stop(176)) - Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2016-01-28 07:56:23,643 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1453966428708_2257_000003
2016-01-28 07:56:23,643 INFO: org.apache.tajo.querymaster.Query (transition(825)) - Complete Stage[eb_1453966428708_2257_000002], State: SUCCEEDED, 2/2.
2016-01-28 07:56:23,643 INFO: org.apache.tajo.querymaster.Query (handle(878)) - Processing q_1453966428708_2257 of type QUERY_COMPLETED
2016-01-28 07:56:23,644 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(160)) - Stopped execution block:eb_1453966428708_2257_000002
2016-01-28 07:56:23,644 INFO: org.apache.tajo.querymaster.Query (handle(896)) - q_1453966428708_2257 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2016-01-28 07:56:23,644 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(297)) - Query completion notified from q_1453966428708_2257 final state: QUERY_SUCCEEDED
2016-01-28 07:56:23,645 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(257)) - Received QueryMaster heartbeat:q_1453966428708_2257,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf901.gq1.ygridcore.net
2016-01-28 07:56:23,645 INFO: org.apache.tajo.master.QueryManager (stopQuery(279)) - Stop QueryInProgress:q_1453966428708_2257
2016-01-28 07:56:23,645 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(122)) - =========================================================
2016-01-28 07:56:23,645 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(123)) - Stop query:q_1453966428708_2257
2016-01-28 07:56:23,646 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(173)) - Stopping QueryMasterTask:q_1453966428708_2257
2016-01-28 07:56:23,647 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(474)) - Cleanup resources of all workers. Query: q_1453966428708_2257, workers: 1
2016-01-28 07:56:23,647 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 62b828f4-ef8c-4843-ae71-a3878d834883 is removed.
2016-01-28 07:56:23,648 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(189)) - Stopped QueryMasterTask:q_1453966428708_2257
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.092 sec - in org.apache.tajo.querymaster.TestQueryProgress
Running org.apache.tajo.TestQueryIdFactory
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.TestQueryIdFactory
Running org.apache.tajo.resource.TestResources
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.apache.tajo.resource.TestResources
2016-01-28 07:56:23,661 INFO: org.mortbay.log (info(67)) - Shutdown hook executing
2016-01-28 07:56:23,663 INFO: org.mortbay.log (info(67)) - Shutdown hook complete
2016-01-28 07:56:23,669 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 3eabe687-9234-4d5d-bf24-bca25c5452ea is removed.
2016-01-28 07:56:23,679 INFO: org.apache.tajo.session.SessionManager (removeSession(85)) - Session 7bd0bfa1-7e25-4ee3-b8d0-8fafc8d954fe is removed.
2016-01-28 07:56:23,680 INFO: org.apache.tajo.worker.TajoWorker (run(518)) - ============================================
2016-01-28 07:56:23,683 INFO: org.apache.tajo.worker.TajoWorker (run(519)) - TajoWorker received SIGINT Signal
2016-01-28 07:56:23,683 INFO: org.apache.tajo.worker.TajoWorker (run(520)) - ============================================
2016-01-28 07:56:23,691 WARN: org.apache.hadoop.hdfs.DFSClient (completeFile(2283)) - Caught exception
java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method)
at org.apache.hadoop.hdfs.DFSOutputStream.completeFile(DFSOutputStream.java:2277)
at org.apache.hadoop.hdfs.DFSOutputStream.closeImpl(DFSOutputStream.java:2238)
at org.apache.hadoop.hdfs.DFSOutputStream.close(DFSOutputStream.java:2204)
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:244)
at org.apache.tajo.util.history.HistoryWriter$WriterThread.writeQueryHistory(HistoryWriter.java:369)
at org.apache.tajo.util.history.HistoryWriter$WriterThread.writeHistory(HistoryWriter.java:318)
at org.apache.tajo.util.history.HistoryWriter$WriterThread.run(HistoryWriter.java:244)
2016-01-28 07:56:23,694 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 07:56:23,699 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2254/eb_1453966428708_2254_000001.hist
2016-01-28 07:56:23,704 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749124_8300{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 0
2016-01-28 07:56:23,706 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2254/eb_1453966428708_2254_000002.hist
2016-01-28 07:56:23,712 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749125_8301{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 774
2016-01-28 07:56:24,114 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2254/eb_1453966428708_2254_000003.hist
2016-01-28 07:56:24,119 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749126_8302{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 0
2016-01-28 07:56:24,132 INFO: org.apache.tajo.worker.NodeStatusUpdater (serviceStop(113)) - NodeStatusUpdater stopped.
2016-01-28 07:56:24,132 INFO: org.apache.tajo.worker.NodeStatusUpdater (run(261)) - Heartbeat Thread stopped.
2016-01-28 07:56:24,133 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:49987) shutdown
2016-01-28 07:56:24,134 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (serviceStop(106)) - QueryMasterManagerService stopped
2016-01-28 07:56:24,134 INFO: org.apache.tajo.querymaster.QueryMaster (run(432)) - QueryMaster heartbeat thread stopped
2016-01-28 07:56:24,136 INFO: org.apache.tajo.querymaster.QueryMaster (serviceStop(164)) - QueryMaster stopped
2016-01-28 07:56:24,136 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(98)) - TajoWorkerClientService stopping
2016-01-28 07:56:24,140 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:49986) shutdown
2016-01-28 07:56:24,140 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(102)) - TajoWorkerClientService stopped
2016-01-28 07:56:24,140 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:49985) shutdown
2016-01-28 07:56:24,140 INFO: org.apache.tajo.worker.TajoWorkerManagerService (serviceStop(93)) - TajoWorkerManagerService stopped
2016-01-28 07:56:24,142 INFO: org.apache.tajo.worker.TajoWorker (serviceStop(332)) - TajoWorker main thread exiting
2016-01-28 07:56:24,146 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(365)) - Saving query summary: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2255/query.hist
2016-01-28 07:56:24,155 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749127_8303{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 0
2016-01-28 07:56:24,159 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2255/eb_1453966428708_2255_000001.hist
2016-01-28 07:56:24,163 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749128_8304{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 480
2016-01-28 07:56:24,565 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(379)) - Saving query unit: hdfs://localhost:38781/tmp/tajo-jenkins/staging/history/20160128/query-detail/q_1453966428708_2255/eb_1453966428708_2255_000002.hist
2016-01-28 07:56:24,568 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073749129_8305{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 0
2016-01-28 07:56:24,569 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_asf901.gq1.ygridcore.net_49985 stopped.
2016-01-28 07:56:26,345 INFO: org.apache.tajo.master.TajoMaster (run(568)) - ============================================
2016-01-28 07:56:26,346 INFO: org.apache.tajo.master.TajoMaster (run(569)) - TajoMaster received SIGINT Signal
2016-01-28 07:56:26,346 INFO: org.apache.tajo.master.TajoMaster (run(570)) - ============================================
2016-01-28 07:56:26,347 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (Tajo-REST) listened on 127.0.0.1:49984) shutdown
2016-01-28 07:56:26,347 INFO: org.apache.tajo.ws.rs.TajoRestService (serviceStop(129)) - Tajo Rest Service stopped.
2016-01-28 07:56:26,352 INFO: org.apache.tajo.util.history.HistoryWriter (run(275)) - HistoryWriter_127.0.0.1_49983 stopped.
2016-01-28 07:56:26,357 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36313 is added to blk_1073741834_1010{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-d885177a-0794-44f8-91b4-c196e5cfe9db:NORMAL:127.0.0.1:36313|RBW]]} size 524
2016-01-28 07:56:26,357 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (QueryCoordinatorProtocol) listened on 127.0.0.1:49983) shutdown
2016-01-28 07:56:26,358 INFO: org.apache.tajo.util.history.HistoryCleaner (run(136)) - History cleaner stopped
2016-01-28 07:56:28,562 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoMasterClientProtocol) listened on 127.0.0.1:49982) shutdown
2016-01-28 07:56:28,563 INFO: org.apache.tajo.catalog.CatalogServer (serviceStop(182)) - Catalog Server (127.0.0.1:49981) shutdown
2016-01-28 07:56:28,563 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (CatalogProtocol) listened on 127.0.0.1:49981) shutdown
2016-01-28 07:56:28,779 INFO: org.apache.tajo.catalog.store.DerbyStore (close(2978)) - Close database (jdbc:derby:memory:<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/8aeee890-8aa1-40b2-94c3-360073d24cf2/db;create=true)>
2016-01-28 07:56:28,780 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(172)) - Rpc (TajoResourceTrackerProtocol) listened on 127.0.0.1:49980) shutdown
2016-01-28 07:56:28,781 INFO: org.apache.tajo.master.TajoMaster (serviceStop(424)) - Tajo Master main thread exiting
2016-01-28 07:56:28,820 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(68)) - Derby shutdown complete normally.
2016-01-28 07:56:28,820 INFO: org.apache.tajo.catalog.store.DerbyStore (shutdown(75)) - Shutdown database
Results :
Tests in error:
TestJoinOnPartitionedTables.testPartialFilterPushDown:95->QueryTestCaseBase.runSimpleTests:622 » UndefinedTable
Tests run: 1734, Failures: 0, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.907 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.779 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.250 s]
[INFO] Tajo Common ....................................... SUCCESS [ 31.283 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.816 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.551 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 7.854 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.253 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [02:24 min]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.725 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 14.030 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 3.767 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [01:14 min]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.079 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.772 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 2.151 s]
[INFO] Tajo SQL Parser ................................... SUCCESS [ 5.079 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.453 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 5.317 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.911 s]
[INFO] Tajo Core ......................................... SUCCESS [ 8.941 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.983 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 12.961 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.073 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 1.126 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.091 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 4.590 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 3.289 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 39.977 s]
[INFO] Tajo JDBC storage common .......................... SUCCESS [ 0.919 s]
[INFO] Tajo PostgreSQL JDBC storage ...................... SUCCESS [ 1.565 s]
[INFO] Tajo S3 storage ................................... SUCCESS [ 0.360 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 1.030 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.952 s]
[INFO] Tajo Core Tests ................................... FAILURE [22:55 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 29:35 min
[INFO] Finished at: 2016-01-28T07:56:29+00:00
[INFO] Final Memory: 162M/2476M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19:test (default-test) on project tajo-core-tests: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Updating TAJO-2065