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 2014/07/11 09:22:50 UTC
Build failed in Jenkins: Tajo-master-build #288
See <https://builds.apache.org/job/Tajo-master-build/288/changes>
Changes:
[hyunsik] TAJO-934: Multiple DISTINCT returns null grouping key value. (Hyoungjun Kim via hyunsik)
------------------------------------------
[...truncated 274794 lines...]
2014-07-11 07:21:47,049 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(478)) - =============================================
2014-07-11 07:21:47,049 INFO: org.apache.tajo.master.GlobalEngine (executeQueryInternal(285)) - Query is forwarded to :0
2014-07-11 07:21:47,049 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:QueryInProgress:q_1405062781233_0648
2014-07-11 07:21:47,050 INFO: org.apache.tajo.master.querymaster.QueryInProgress (startQueryMaster(165)) - Initializing QueryInProgress for QueryID=q_1405062781233_0648
2014-07-11 07:21:47,050 INFO: org.apache.tajo.master.querymaster.QueryInProgress (connectQueryMaster(209)) - Connect to QueryMaster:asf905.gq1.ygridcore.net/67.195.81.149:45267
2014-07-11 07:21:47,051 INFO: org.apache.tajo.master.querymaster.QueryInProgress (submmitQueryToMaster(229)) - Call executeQuery to :asf905.gq1.ygridcore.net:45267,q_1405062781233_0648
2014-07-11 07:21:47,053 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (executeQuery(236)) - Receive executeQuery request:q_1405062781233_0648
2014-07-11 07:21:47,053 INFO: org.apache.tajo.master.querymaster.QueryMaster (handle(374)) - Start QueryStartEventHandler:q_1405062781233_0648
2014-07-11 07:21:47,057 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (initStagingDir(380)) - The staging dir 'hdfs://localhost:55834/tmp/tajo-jenkins/staging/q_1405062781233_0648' is created.
2014-07-11 07:21:47,077 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(116)) -
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND default.lineitem.l_quantity (FLOAT8) > 20.0
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_returnflag (TEXT)
=> out schema: {(3) default.lineitem.l_orderkey (INT4),default.lineitem.l_quantity (FLOAT8),default.lineitem.l_returnflag (TEXT)}
=> 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)}
2014-07-11 07:21:47,078 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(159)) -
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1405062781233_0648_000002)
-------------------------------------------------------------------------------
|-eb_1405062781233_0648_000002
|-eb_1405062781233_0648_000001
-------------------------------------------------------------------------------
Order of Execution
-------------------------------------------------------------------------------
1: eb_1405062781233_0648_000001
2: eb_1405062781233_0648_000002
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1405062781233_0648_000001 [ROOT]
=======================================================
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND default.lineitem.l_quantity (FLOAT8) > 20.0
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_returnflag (TEXT)
=> out schema: {(3) default.lineitem.l_orderkey (INT4),default.lineitem.l_quantity (FLOAT8),default.lineitem.l_returnflag (TEXT)}
=> 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_1405062781233_0648_000002 [TERMINAL]
=======================================================
2014-07-11 07:21:47,078 INFO: org.apache.tajo.master.querymaster.Query (<init>(223)) -
=======================================================
The order of execution:
1: eb_1405062781233_0648_000001
2: eb_1405062781233_0648_000002
=======================================================
2014-07-11 07:21:47,078 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:q_1405062781233_0648
2014-07-11 07:21:47,078 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405062781233_0648 of type START
2014-07-11 07:21:47,079 INFO: org.apache.tajo.master.querymaster.SubQuery (initTaskScheduler(677)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1405062781233_0648_000001
2014-07-11 07:21:47,082 INFO: org.apache.tajo.storage.AbstractStorageManager (listStatus(386)) - Total input paths to process : 1
2014-07-11 07:21:47,083 INFO: org.apache.tajo.storage.AbstractStorageManager (getSplits(615)) - Total # of splits: 1
2014-07-11 07:21:47,084 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(647)) - 1 objects are scheduled
2014-07-11 07:21:47,084 INFO: org.apache.tajo.master.DefaultTaskScheduler (start(87)) - Start TaskScheduler
2014-07-11 07:21:47,084 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-07-11 07:21:47,084 INFO: org.apache.tajo.master.querymaster.SubQuery (allocateContainers(890)) - Request Container for eb_1405062781233_0648_000001 containers=1
2014-07-11 07:21:47,084 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405062781233_0648 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-07-11 07:21:47,085 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(217)) - Start TajoWorkerAllocationThread
2014-07-11 07:21:47,086 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(336)) - Stop TajoWorkerAllocationThread
2014-07-11 07:21:47,086 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(999)) - SubQuery (eb_1405062781233_0648_000001) has 1 containers!
2014-07-11 07:21:47,088 INFO: org.apache.tajo.worker.TaskRunner (<init>(122)) - Tajo Root Dir: hdfs://localhost:55834/tajo
2014-07-11 07:21:47,088 INFO: org.apache.tajo.worker.TaskRunner (<init>(123)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/df4fa5d0-33c6-438e-adb5-c28919305e07/tajo-localdir>
2014-07-11 07:21:47,088 INFO: org.apache.tajo.worker.TaskRunner (<init>(138)) - QueryMaster Address:asf905.gq1.ygridcore.net/67.195.81.149:45267
2014-07-11 07:21:47,089 INFO: org.apache.tajo.worker.TaskRunnerManager (run(156)) - Start TaskRunner:eb_1405062781233_0648_000001,container_1405062781233_0648_01_002571
2014-07-11 07:21:47,089 INFO: org.apache.tajo.worker.TaskRunner (init(191)) - TaskRunner basedir is created (q_1405062781233_0648/output/1)
2014-07-11 07:21:47,090 INFO: org.apache.tajo.worker.TaskRunner (run(327)) - TaskRunner startup
2014-07-11 07:21:47,090 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405062781233_0648_000001,container_1405062781233_0648_01_002571
2014-07-11 07:21:47,091 INFO: org.apache.tajo.master.DefaultTaskScheduler (allocateRackTask(718)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: 67.195.81.149
2014-07-11 07:21:47,093 INFO: org.apache.tajo.worker.TaskRunner (run(385)) - Accumulated Received Task: 1
2014-07-11 07:21:47,093 INFO: org.apache.tajo.worker.TaskRunner (run(394)) - Initializing: ta_1405062781233_0648_000001_000000_00
2014-07-11 07:21:47,094 INFO: org.apache.tajo.worker.Task (<init>(184)) - Output File Path: hdfs://localhost:55834/tmp/tajo-jenkins/staging/q_1405062781233_0648/RESULT/part-01-000000
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405062781233_0648_000001_000000_00 is changed to TA_PENDING
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(189)) - ==================================
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(190)) - * Subquery ta_1405062781233_0648_000001_000000_00 is initialized
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(191)) - * InterQuery: false
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(194)) - * Fragments (num: 1)
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(195)) - * Fetches (total:0) :
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(199)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/df4fa5d0-33c6-438e-adb5-c28919305e07/tajo-localdir/q_1405062781233_0648/output/1/0_0>
2014-07-11 07:21:47,095 INFO: org.apache.tajo.worker.Task (<init>(204)) - ==================================
2014-07-11 07:21:47,096 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405062781233_0648_000001_000000_00 is changed to TA_RUNNING
2014-07-11 07:21:47,109 INFO: BlockStateChange (logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48938 is added to blk_1073742863_2039{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-f3b669ce-fab4-4218-ab8c-19028e8ab32c:NORMAL|RBW]]} size 0
2014-07-11 07:21:47,110 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405062781233_0648_000001_000000_00 is changed to TA_SUCCEEDED
2014-07-11 07:21:47,110 INFO: org.apache.tajo.worker.Task (run(467)) - Worker's task counter - total:1, succeeded: 1, killed: 1, failed: 0
2014-07-11 07:21:47,110 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405062781233_0648_000001,container_1405062781233_0648_01_002571
2014-07-11 07:21:47,110 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1076)) - [eb_1405062781233_0648_000001] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-07-11 07:21:47,111 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1116)) - subQuery completed - eb_1405062781233_0648_000001 (total=1, success=1, killed=0)
2014-07-11 07:21:47,111 INFO: org.apache.tajo.master.DefaultTaskScheduler (run(102)) - TaskScheduler schedulingThread stopped
2014-07-11 07:21:47,111 INFO: org.apache.tajo.master.DefaultTaskScheduler (stop(143)) - Task Scheduler stopped
2014-07-11 07:21:47,111 INFO: org.apache.tajo.worker.TaskRunner (run(376)) - Received ShouldDie flag:eb_1405062781233_0648_000001,container_1405062781233_0648_01_002571
2014-07-11 07:21:47,111 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405062781233_0648 of type SUBQUERY_COMPLETED
2014-07-11 07:21:47,111 INFO: org.apache.tajo.worker.TaskRunner (stop(239)) - Stop TaskRunner: eb_1405062781233_0648_000001
2014-07-11 07:21:47,112 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTask(89)) - Stop Task:eb_1405062781233_0648_000001,container_1405062781233_0648_01_002571
2014-07-11 07:21:47,112 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405062781233_0648 of type QUERY_COMPLETED
2014-07-11 07:21:47,112 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.5,512
2014-07-11 07:21:47,113 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405062781233_0648 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-07-11 07:21:47,113 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(297)) - Query completion notified from q_1405062781233_0648
2014-07-11 07:21:47,113 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(308)) - Query final state: QUERY_SUCCEEDED
2014-07-11 07:21:47,113 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(187)) - Stopping QueryMasterTask:q_1405062781233_0648
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.querymaster.QueryJobManager (stopQuery(203)) - Stop QueryInProgress:q_1405062781233_0648
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(116)) - =========================================================
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(117)) - Stop query:q_1405062781233_0648
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.0,512
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (stopQueryMaster(541)) - Released QueryMaster (q_1405062781233_0648) resource.
2014-07-11 07:21:47,115 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(125)) - q_1405062781233_0648 QueryMaster stopped
2014-07-11 07:21:47,114 INFO: org.apache.tajo.master.querymaster.QueryInProgress (heartbeat(265)) - Received QueryMaster heartbeat:q_1405062781233_0648,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf905.gq1.ygridcore.net
2014-07-11 07:21:47,116 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1405062781233_0648
2014-07-11 07:21:47,117 WARN: org.apache.tajo.master.TajoAsyncDispatcher (stop(115)) - Interrupted Exception while stopping
2014-07-11 07:21:47,117 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:q_1405062781233_0648
2014-07-11 07:21:47,117 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(217)) - Stopped QueryMasterTask:q_1405062781233_0648
2014-07-11 07:21:47,118 INFO: org.apache.tajo.master.querymaster.QueryMaster (cleanup(166)) - cleanup query resources : q_1405062781233_0648
2014-07-11 07:21:47,563 INFO: org.apache.tajo.worker.TajoWorkerClientService (closeQuery(231)) - Stop Query:q_1405062781233_0648
2014-07-11 07:21:47,566 INFO: org.apache.tajo.master.GlobalEngine (dropDatabase(788)) - database TestTajoJdbc is dropped.
2014-07-11 07:21:47,568 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session 31130226-51ef-4253-ba01-3c91053a26d1 is removed.
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.181 sec
2014-07-11 07:21:47,577 INFO: org.apache.tajo.worker.TajoWorker (run(492)) - ============================================
2014-07-11 07:21:47,583 INFO: org.apache.tajo.worker.TajoWorker (run(493)) - TajoWorker received SIGINT Signal
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.InternalParquetRecordWriter: Flushing mem store to file. allocated memory: 63,754,392
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_orderkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 3 entries, 12B raw, 3B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_partkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 3 entries, 12B raw, 3B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_suppkey] INT32: 5 values, 26B raw, 26B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_linenumber] INT32: 5 values, 9B raw, 9B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 2 entries, 8B raw, 2B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_quantity] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_extendedprice] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_discount] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_tax] DOUBLE: 5 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 4 entries, 32B raw, 4B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_returnflag] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 2 entries, 10B raw, 2B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_linestatus] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 2 entries, 10B raw, 2B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_commitdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_receiptdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_shipinstruct] BINARY: 5 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 3 entries, 49B raw, 3B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_shipmode] BINARY: 5 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 4 entries, 32B raw, 4B comp}
Jul 11, 2014 7:18:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 190B for [l_comment] BINARY: 5 values, 171B raw, 171B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordWriter: Flushing mem store to file. allocated memory: 63,753,806
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_orderkey] INT32: 2 values, 8B raw, 8B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 1 entries, 4B raw, 1B comp}
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_partkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_suppkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_linenumber] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_quantity] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_extendedprice] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_discount] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_tax] DOUBLE: 2 values, 8B raw, 8B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 1 entries, 8B raw, 1B comp}
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_returnflag] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 1 entries, 5B raw, 1B comp}
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_linestatus] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings: [PLAIN_DICTIONARY, RLE, BIT_PACKED], dic { 1 entries, 5B raw, 1B comp}
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_shipdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_commitdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_receiptdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_shipinstruct] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 38B for [l_shipmode] BINARY: 2 values, 21B raw, 21B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 90B for [l_comment] BINARY: 2 values, 71B raw, 71B comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 2 records.
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block read in memory in 7 ms. row count = 2
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 2 records.
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 11, 2014 7:18:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 2
2014-07-11 07:21:47,583 INFO: org.apache.tajo.worker.TajoWorker (run(494)) - ============================================
2014-07-11 07:21:47,587 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session 7e0c28ac-f155-460a-905b-5fafe0bdf196 is removed.
2014-07-11 07:21:47,587 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session d0c49c42-abda-475a-8505-6e77f80e26b7 is removed.
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,588 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,587 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 07:21:47,591 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,591 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,591 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,591 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,590 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,589 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,592 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:45264 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 07:21:47,604 INFO: org.apache.tajo.worker.WorkerHeartbeatService (run(260)) - Worker Resource Heartbeat Thread stopped.
2014-07-11 07:21:47,653 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:45268) shutdown
2014-07-11 07:21:47,656 INFO: org.apache.tajo.worker.TajoWorkerManagerService (stop(95)) - TajoWorkerManagerService stopped
2014-07-11 07:21:47,665 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:45267) shutdown
2014-07-11 07:21:47,665 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) - QueryMasterManagerService stopped
2014-07-11 07:21:47,666 INFO: org.apache.tajo.master.querymaster.QueryMaster (run(433)) - QueryMaster heartbeat thread stopped
2014-07-11 07:21:47,666 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:querymaster_1405062781880
2014-07-11 07:21:47,667 INFO: org.apache.tajo.master.querymaster.QueryMaster (stop(159)) - QueryMaster stop
2014-07-11 07:21:47,667 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(110)) - TajoWorkerClientService stopping
2014-07-11 07:21:47,670 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:45266) shutdown
2014-07-11 07:21:47,670 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(114)) - TajoWorkerClientService stopped
2014-07-11 07:21:47,670 INFO: org.apache.tajo.worker.TajoWorker (stop(334)) - TajoWorker main thread exiting
Results :
Failed tests: testGroupByWithConstantKeys2(org.apache.tajo.engine.query.TestGroupByQuery): Result Verification expected:<...-------------------(..)
Tests run: 1058, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 5.449 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 0.730 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.726 s]
[INFO] Tajo Common ....................................... SUCCESS [ 37.488 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 1.300 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.309 s]
[INFO] Tajo Rpc .......................................... SUCCESS [ 21.374 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 0.999 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 5.517 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 42.460 s]
[INFO] Tajo Core PullServer .............................. SUCCESS [ 0.679 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.918 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.432 s]
[INFO] Tajo Core ......................................... FAILURE [09:04 min]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 11:12 min
[INFO] Finished at: 2014-07-11T07:21:48+00:00
[INFO] Final Memory: 95M/1931M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on project tajo-core: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core
Build step 'Execute shell' marked build as failure
Updating TAJO-934
Jenkins build is back to normal : Tajo-master-build #291
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/291/changes>
Build failed in Jenkins: Tajo-master-build #290
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/290/changes>
Changes:
[hyunsik] TAJO-926: Join condition including column references of a row-preserving table in left outer join causes incorrect result.
------------------------------------------
[...truncated 281212 lines...]
2014-07-11 09:31:32,252 INFO: org.apache.tajo.master.GlobalEngine (createTableOnPath(731)) - Table default.nulltable1 is created (30)
2014-07-11 09:31:32,254 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session da1d534e-0f99-46cf-9d45-fff29ceb5b0a is removed.
2014-07-11 09:31:33,257 INFO: org.apache.tajo.master.session.SessionManager (createSession(73)) - Session ac049b73-d505-413c-9c44-d260eec2af82 is created.
2014-07-11 09:31:33,257 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(118)) - Query: select * from nulltable1 where col3 is null
2014-07-11 09:31:33,275 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(474)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
PROJECTION(2)
=> Targets: default.nulltable1.col1 (INT4), default.nulltable1.col2 (TEXT), default.nulltable1.col3 (FLOAT4)
=> out schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
=> in schema: {(4) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4),?isnullpredicate (BOOLEAN)}
SELECTION(1)
=> Search Cond: default.nulltable1.col3 (FLOAT4) IS NULL
SCAN(0) on default.nulltable1
=> target list: default.nulltable1.col1 (INT4), default.nulltable1.col2 (TEXT), default.nulltable1.col3 (FLOAT4), default.nulltable1.col3 (FLOAT4) IS NULL as ?isnullpredicate
=> out schema: {(4) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4),?isnullpredicate (BOOLEAN)}
=> in schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
2014-07-11 09:31:33,276 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(476)) - =============================================
2014-07-11 09:31:33,276 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(477)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
SCAN(0) on default.nulltable1
=> filter: default.nulltable1.col3 (FLOAT4) IS NULL
=> target list: default.nulltable1.col1 (INT4), default.nulltable1.col2 (TEXT), default.nulltable1.col3 (FLOAT4)
=> out schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
=> in schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
2014-07-11 09:31:33,276 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(478)) - =============================================
2014-07-11 09:31:33,277 INFO: org.apache.tajo.master.GlobalEngine (executeQueryInternal(285)) - Query is forwarded to :0
2014-07-11 09:31:33,277 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:QueryInProgress:q_1405070560436_0652
2014-07-11 09:31:33,277 INFO: org.apache.tajo.master.querymaster.QueryInProgress (startQueryMaster(165)) - Initializing QueryInProgress for QueryID=q_1405070560436_0652
2014-07-11 09:31:33,278 INFO: org.apache.tajo.master.querymaster.QueryInProgress (connectQueryMaster(209)) - Connect to QueryMaster:asf902.gq1.ygridcore.net/67.195.81.146:43679
2014-07-11 09:31:33,278 INFO: org.apache.tajo.master.querymaster.QueryInProgress (submmitQueryToMaster(229)) - Call executeQuery to :asf902.gq1.ygridcore.net:43679,q_1405070560436_0652
2014-07-11 09:31:33,280 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (executeQuery(236)) - Receive executeQuery request:q_1405070560436_0652
2014-07-11 09:31:33,280 INFO: org.apache.tajo.master.querymaster.QueryMaster (handle(374)) - Start QueryStartEventHandler:q_1405070560436_0652
2014-07-11 09:31:33,284 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (initStagingDir(380)) - The staging dir 'hdfs://localhost:53114/tmp/tajo-jenkins/staging/q_1405070560436_0652' is created.
2014-07-11 09:31:33,306 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(116)) -
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
SCAN(0) on default.nulltable1
=> filter: default.nulltable1.col3 (FLOAT4) IS NULL
=> target list: default.nulltable1.col1 (INT4), default.nulltable1.col2 (TEXT), default.nulltable1.col3 (FLOAT4)
=> out schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
=> in schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
2014-07-11 09:31:33,306 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(159)) -
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1405070560436_0652_000002)
-------------------------------------------------------------------------------
|-eb_1405070560436_0652_000002
|-eb_1405070560436_0652_000001
-------------------------------------------------------------------------------
Order of Execution
-------------------------------------------------------------------------------
1: eb_1405070560436_0652_000001
2: eb_1405070560436_0652_000002
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1405070560436_0652_000001 [ROOT]
=======================================================
SCAN(0) on default.nulltable1
=> filter: default.nulltable1.col3 (FLOAT4) IS NULL
=> target list: default.nulltable1.col1 (INT4), default.nulltable1.col2 (TEXT), default.nulltable1.col3 (FLOAT4)
=> out schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
=> in schema: {(3) default.nulltable1.col1 (INT4),default.nulltable1.col2 (TEXT),default.nulltable1.col3 (FLOAT4)}
=======================================================
Block Id: eb_1405070560436_0652_000002 [TERMINAL]
=======================================================
2014-07-11 09:31:33,306 INFO: org.apache.tajo.master.querymaster.Query (<init>(223)) -
=======================================================
The order of execution:
1: eb_1405070560436_0652_000001
2: eb_1405070560436_0652_000002
=======================================================
2014-07-11 09:31:33,307 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:q_1405070560436_0652
2014-07-11 09:31:33,307 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405070560436_0652 of type START
2014-07-11 09:31:33,307 INFO: org.apache.tajo.master.querymaster.SubQuery (initTaskScheduler(677)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1405070560436_0652_000001
2014-07-11 09:31:33,310 INFO: org.apache.tajo.storage.AbstractStorageManager (listStatus(386)) - Total input paths to process : 1
2014-07-11 09:31:33,311 INFO: org.apache.tajo.storage.AbstractStorageManager (getSplits(615)) - Total # of splits: 1
2014-07-11 09:31:33,311 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(647)) - 1 objects are scheduled
2014-07-11 09:31:33,311 INFO: org.apache.tajo.master.DefaultTaskScheduler (start(87)) - Start TaskScheduler
2014-07-11 09:31:33,312 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-07-11 09:31:33,312 INFO: org.apache.tajo.master.querymaster.SubQuery (allocateContainers(890)) - Request Container for eb_1405070560436_0652_000001 containers=1
2014-07-11 09:31:33,312 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405070560436_0652 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-07-11 09:31:33,313 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(217)) - Start TajoWorkerAllocationThread
2014-07-11 09:31:33,314 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(336)) - Stop TajoWorkerAllocationThread
2014-07-11 09:31:33,314 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(999)) - SubQuery (eb_1405070560436_0652_000001) has 1 containers!
2014-07-11 09:31:33,315 INFO: org.apache.tajo.worker.TaskRunner (<init>(122)) - Tajo Root Dir: hdfs://localhost:53114/tajo
2014-07-11 09:31:33,316 INFO: org.apache.tajo.worker.TaskRunner (<init>(123)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/c09ba2a3-a751-4535-a467-27bdbb4a375b/tajo-localdir>
2014-07-11 09:31:33,316 INFO: org.apache.tajo.worker.TaskRunner (<init>(138)) - QueryMaster Address:asf902.gq1.ygridcore.net/67.195.81.146:43679
2014-07-11 09:31:33,316 INFO: org.apache.tajo.worker.TaskRunnerManager (run(156)) - Start TaskRunner:eb_1405070560436_0652_000001,container_1405070560436_0652_01_002587
2014-07-11 09:31:33,317 INFO: org.apache.tajo.worker.TaskRunner (init(191)) - TaskRunner basedir is created (q_1405070560436_0652/output/1)
2014-07-11 09:31:33,317 INFO: org.apache.tajo.worker.TaskRunner (run(327)) - TaskRunner startup
2014-07-11 09:31:33,318 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405070560436_0652_000001,container_1405070560436_0652_01_002587
2014-07-11 09:31:33,319 INFO: org.apache.tajo.master.DefaultTaskScheduler (allocateRackTask(718)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: 67.195.81.146
2014-07-11 09:31:33,320 INFO: org.apache.tajo.worker.TaskRunner (run(385)) - Accumulated Received Task: 1
2014-07-11 09:31:33,320 INFO: org.apache.tajo.worker.TaskRunner (run(394)) - Initializing: ta_1405070560436_0652_000001_000000_00
2014-07-11 09:31:33,321 INFO: org.apache.tajo.worker.Task (<init>(184)) - Output File Path: hdfs://localhost:53114/tmp/tajo-jenkins/staging/q_1405070560436_0652/RESULT/part-01-000000
2014-07-11 09:31:33,321 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405070560436_0652_000001_000000_00 is changed to TA_PENDING
2014-07-11 09:31:33,321 INFO: org.apache.tajo.worker.Task (<init>(189)) - ==================================
2014-07-11 09:31:33,321 INFO: org.apache.tajo.worker.Task (<init>(190)) - * Subquery ta_1405070560436_0652_000001_000000_00 is initialized
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.Task (<init>(191)) - * InterQuery: false
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.Task (<init>(194)) - * Fragments (num: 1)
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.Task (<init>(195)) - * Fetches (total:0) :
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.Task (<init>(199)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/c09ba2a3-a751-4535-a467-27bdbb4a375b/tajo-localdir/q_1405070560436_0652/output/1/0_0>
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.Task (<init>(204)) - ==================================
2014-07-11 09:31:33,322 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405070560436_0652_000001_000000_00 is changed to TA_RUNNING
2014-07-11 09:31:33,336 INFO: BlockStateChange (logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:56925 is added to blk_1073742867_2043{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-85bb041e-5656-4bcc-8b86-c054b40bc416:NORMAL|RBW]]} size 0
2014-07-11 09:31:33,337 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405070560436_0652_000001_000000_00 is changed to TA_SUCCEEDED
2014-07-11 09:31:33,337 INFO: org.apache.tajo.worker.Task (run(467)) - Worker's task counter - total:1, succeeded: 1, killed: 1, failed: 0
2014-07-11 09:31:33,337 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405070560436_0652_000001,container_1405070560436_0652_01_002587
2014-07-11 09:31:33,338 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1076)) - [eb_1405070560436_0652_000001] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-07-11 09:31:33,338 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1116)) - subQuery completed - eb_1405070560436_0652_000001 (total=1, success=1, killed=0)
2014-07-11 09:31:33,338 INFO: org.apache.tajo.master.DefaultTaskScheduler (run(102)) - TaskScheduler schedulingThread stopped
2014-07-11 09:31:33,338 INFO: org.apache.tajo.master.DefaultTaskScheduler (stop(143)) - Task Scheduler stopped
2014-07-11 09:31:33,338 INFO: org.apache.tajo.worker.TaskRunner (run(376)) - Received ShouldDie flag:eb_1405070560436_0652_000001,container_1405070560436_0652_01_002587
2014-07-11 09:31:33,339 INFO: org.apache.tajo.worker.TaskRunner (stop(239)) - Stop TaskRunner: eb_1405070560436_0652_000001
2014-07-11 09:31:33,339 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405070560436_0652 of type SUBQUERY_COMPLETED
2014-07-11 09:31:33,339 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTask(89)) - Stop Task:eb_1405070560436_0652_000001,container_1405070560436_0652_01_002587
2014-07-11 09:31:33,339 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.5,512
2014-07-11 09:31:33,339 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405070560436_0652 of type QUERY_COMPLETED
2014-07-11 09:31:33,340 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405070560436_0652 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(297)) - Query completion notified from q_1405070560436_0652
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(308)) - Query final state: QUERY_SUCCEEDED
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(187)) - Stopping QueryMasterTask:q_1405070560436_0652
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryJobManager (stopQuery(203)) - Stop QueryInProgress:q_1405070560436_0652
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(116)) - =========================================================
2014-07-11 09:31:33,342 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(117)) - Stop query:q_1405070560436_0652
2014-07-11 09:31:33,342 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.0,512
2014-07-11 09:31:33,342 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (stopQueryMaster(541)) - Released QueryMaster (q_1405070560436_0652) resource.
2014-07-11 09:31:33,342 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(125)) - q_1405070560436_0652 QueryMaster stopped
2014-07-11 09:31:33,341 INFO: org.apache.tajo.master.querymaster.QueryInProgress (heartbeat(265)) - Received QueryMaster heartbeat:q_1405070560436_0652,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf902.gq1.ygridcore.net
2014-07-11 09:31:33,344 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1405070560436_0652
2014-07-11 09:31:33,344 WARN: org.apache.tajo.master.TajoAsyncDispatcher (stop(115)) - Interrupted Exception while stopping
2014-07-11 09:31:33,345 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:q_1405070560436_0652
2014-07-11 09:31:33,345 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(217)) - Stopped QueryMasterTask:q_1405070560436_0652
2014-07-11 09:31:33,345 INFO: org.apache.tajo.master.querymaster.QueryMaster (cleanup(166)) - cleanup query resources : q_1405070560436_0652
2014-07-11 09:31:33,787 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session ac049b73-d505-413c-9c44-d260eec2af82 is removed.
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 9 sec
2014-07-11 09:31:33,795 INFO: org.apache.tajo.worker.TajoWorker (run(492)) - ============================================
2014-07-11 09:31:33,795 INFO: org.apache.tajo.worker.TajoWorker (run(493)) - TajoWorker received SIGINT Signal
2014-07-11 09:31:33,795 INFO: org.apache.tajo.worker.TajoWorker (run(494)) - ============================================
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,800 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session d6294e0d-bc88-49a8-af9c-937fffddf445 is removed.
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,801 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,802 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,802 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 09:31:33,802 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,802 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,801 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session a497806e-340a-4c6a-8005-030ff2fa637f is removed.
2014-07-11 09:31:33,800 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,803 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:43676 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 09:31:33,809 INFO: org.apache.tajo.worker.WorkerHeartbeatService (run(260)) - Worker Resource Heartbeat Thread stopped.
2014-07-11 09:31:33,862 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:43680) shutdown
2014-07-11 09:31:33,862 INFO: org.apache.tajo.worker.TajoWorkerManagerService (stop(95)) - TajoWorkerManagerService stopped
2014-07-11 09:31:33,868 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:43679) shutdown
2014-07-11 09:31:33,869 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) - QueryMasterManagerService stopped
2014-07-11 09:31:33,869 INFO: org.apache.tajo.master.querymaster.QueryMaster (run(433)) - QueryMaster heartbeat thread stopped
2014-07-11 09:31:33,870 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:querymaster_1405070561130
2014-07-11 09:31:33,870 INFO: org.apache.tajo.master.querymaster.QueryMaster (stop(159)) - QueryMaster stop
2014-07-11 09:31:33,870 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(110)) - TajoWorkerClientService stopping
2014-07-11 09:31:33,873 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:43678) shutdown
2014-07-11 09:31:33,874 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(114)) - TajoWorkerClientService stopped
2014-07-11 09:31:33,874 INFO: org.apache.tajo.worker.TajoWorker (stop(334)) - TajoWorker main thread exiting
Results :
Failed tests: testGroupByWithConstantKeys2(org.apache.tajo.engine.query.TestGroupByQuery): Result Verification expected:<...-------------------(..)
Tests run: 1062, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 4.001 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.305 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.797 s]
[INFO] Tajo Common ....................................... SUCCESS [ 41.548 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 3.914 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.110 s]
[INFO] Tajo Rpc .......................................... SUCCESS [ 24.133 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.039 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 7.657 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 57.125 s]
[INFO] Tajo Core PullServer .............................. SUCCESS [ 1.031 s]
[INFO] Tajo Client ....................................... SUCCESS [ 3.795 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.473 s]
[INFO] Tajo Core ......................................... FAILURE [09:19 min]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 11:54 min
[INFO] Finished at: 2014-07-11T09:31:34+00:00
[INFO] Final Memory: 78M/926M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on project tajo-core: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core
Build step 'Execute shell' marked build as failure
Updating TAJO-926
Build failed in Jenkins: Tajo-master-build #289
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/289/changes>
Changes:
[jinossy] TAJO-852: Integration test using HCatalog as a catalog store is failed. (jinho)
------------------------------------------
[...truncated 274727 lines...]
2014-07-11 08:16:48,539 INFO: org.apache.tajo.master.GlobalEngine (executeQueryInternal(285)) - Query is forwarded to :0
2014-07-11 08:16:48,540 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:QueryInProgress:q_1405066083048_0648
2014-07-11 08:16:48,540 INFO: org.apache.tajo.master.querymaster.QueryInProgress (startQueryMaster(165)) - Initializing QueryInProgress for QueryID=q_1405066083048_0648
2014-07-11 08:16:48,540 INFO: org.apache.tajo.master.querymaster.QueryInProgress (connectQueryMaster(209)) - Connect to QueryMaster:asf905.gq1.ygridcore.net/67.195.81.149:18681
2014-07-11 08:16:48,541 INFO: org.apache.tajo.master.querymaster.QueryInProgress (submmitQueryToMaster(229)) - Call executeQuery to :asf905.gq1.ygridcore.net:18681,q_1405066083048_0648
2014-07-11 08:16:48,543 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (executeQuery(236)) - Receive executeQuery request:q_1405066083048_0648
2014-07-11 08:16:48,543 INFO: org.apache.tajo.master.querymaster.QueryMaster (handle(374)) - Start QueryStartEventHandler:q_1405066083048_0648
2014-07-11 08:16:48,547 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (initStagingDir(380)) - The staging dir 'hdfs://localhost:54489/tmp/tajo-jenkins/staging/q_1405066083048_0648' is created.
2014-07-11 08:16:48,569 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(116)) -
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
[LogicalPlan]
> ProjectionNode is eliminated.
-----------------------------
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND default.lineitem.l_quantity (FLOAT8) > 20.0
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_returnflag (TEXT)
=> out schema: {(3) default.lineitem.l_orderkey (INT4),default.lineitem.l_quantity (FLOAT8),default.lineitem.l_returnflag (TEXT)}
=> 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)}
2014-07-11 08:16:48,570 INFO: org.apache.tajo.engine.planner.global.GlobalPlanner (build(159)) -
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1405066083048_0648_000002)
-------------------------------------------------------------------------------
|-eb_1405066083048_0648_000002
|-eb_1405066083048_0648_000001
-------------------------------------------------------------------------------
Order of Execution
-------------------------------------------------------------------------------
1: eb_1405066083048_0648_000001
2: eb_1405066083048_0648_000002
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1405066083048_0648_000001 [ROOT]
=======================================================
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND default.lineitem.l_quantity (FLOAT8) > 20.0
=> target list: default.lineitem.l_orderkey (INT4), default.lineitem.l_quantity (FLOAT8), default.lineitem.l_returnflag (TEXT)
=> out schema: {(3) default.lineitem.l_orderkey (INT4),default.lineitem.l_quantity (FLOAT8),default.lineitem.l_returnflag (TEXT)}
=> 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_1405066083048_0648_000002 [TERMINAL]
=======================================================
2014-07-11 08:16:48,570 INFO: org.apache.tajo.master.querymaster.Query (<init>(223)) -
=======================================================
The order of execution:
1: eb_1405066083048_0648_000001
2: eb_1405066083048_0648_000002
=======================================================
2014-07-11 08:16:48,570 INFO: org.apache.tajo.master.TajoAsyncDispatcher (start(101)) - AsyncDispatcher started:q_1405066083048_0648
2014-07-11 08:16:48,571 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405066083048_0648 of type START
2014-07-11 08:16:48,571 INFO: org.apache.tajo.master.querymaster.SubQuery (initTaskScheduler(677)) - org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling for eb_1405066083048_0648_000001
2014-07-11 08:16:48,574 INFO: org.apache.tajo.storage.AbstractStorageManager (listStatus(386)) - Total input paths to process : 1
2014-07-11 08:16:48,576 INFO: org.apache.tajo.storage.AbstractStorageManager (getSplits(615)) - Total # of splits: 1
2014-07-11 08:16:48,576 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(647)) - 1 objects are scheduled
2014-07-11 08:16:48,577 INFO: org.apache.tajo.master.DefaultTaskScheduler (start(87)) - Start TaskScheduler
2014-07-11 08:16:48,577 INFO: org.apache.tajo.worker.TajoResourceAllocator (calculateNumRequestContainers(100)) - CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-07-11 08:16:48,577 INFO: org.apache.tajo.master.querymaster.SubQuery (allocateContainers(890)) - Request Container for eb_1405066083048_0648_000001 containers=1
2014-07-11 08:16:48,578 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405066083048_0648 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-07-11 08:16:48,578 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(217)) - Start TajoWorkerAllocationThread
2014-07-11 08:16:48,581 INFO: org.apache.tajo.worker.TajoResourceAllocator (run(336)) - Stop TajoWorkerAllocationThread
2014-07-11 08:16:48,581 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(999)) - SubQuery (eb_1405066083048_0648_000001) has 1 containers!
2014-07-11 08:16:48,583 INFO: org.apache.tajo.worker.TaskRunner (<init>(122)) - Tajo Root Dir: hdfs://localhost:54489/tajo
2014-07-11 08:16:48,583 INFO: org.apache.tajo.worker.TaskRunner (<init>(123)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3669b056-176b-4005-a45c-60cd54a9ea19/tajo-localdir>
2014-07-11 08:16:48,584 INFO: org.apache.tajo.worker.TaskRunner (<init>(138)) - QueryMaster Address:asf905.gq1.ygridcore.net/67.195.81.149:18681
2014-07-11 08:16:48,584 INFO: org.apache.tajo.worker.TaskRunnerManager (run(156)) - Start TaskRunner:eb_1405066083048_0648_000001,container_1405066083048_0648_01_002571
2014-07-11 08:16:48,585 INFO: org.apache.tajo.worker.TaskRunner (init(191)) - TaskRunner basedir is created (q_1405066083048_0648/output/1)
2014-07-11 08:16:48,585 INFO: org.apache.tajo.worker.TaskRunner (run(327)) - TaskRunner startup
2014-07-11 08:16:48,586 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405066083048_0648_000001,container_1405066083048_0648_01_002571
2014-07-11 08:16:48,587 INFO: org.apache.tajo.master.DefaultTaskScheduler (allocateRackTask(718)) - Assigned Local/Rack/Total: (0/1/1), Locality: 0.00%, Rack host: 67.195.81.149
2014-07-11 08:16:48,589 INFO: org.apache.tajo.worker.TaskRunner (run(385)) - Accumulated Received Task: 1
2014-07-11 08:16:48,589 INFO: org.apache.tajo.worker.TaskRunner (run(394)) - Initializing: ta_1405066083048_0648_000001_000000_00
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(184)) - Output File Path: hdfs://localhost:54489/tmp/tajo-jenkins/staging/q_1405066083048_0648/RESULT/part-01-000000
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405066083048_0648_000001_000000_00 is changed to TA_PENDING
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(189)) - ==================================
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(190)) - * Subquery ta_1405066083048_0648_000001_000000_00 is initialized
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(191)) - * InterQuery: false
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(194)) - * Fragments (num: 1)
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(195)) - * Fetches (total:0) :
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(199)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/test-data/3669b056-176b-4005-a45c-60cd54a9ea19/tajo-localdir/q_1405066083048_0648/output/1/0_0>
2014-07-11 08:16:48,591 INFO: org.apache.tajo.worker.Task (<init>(204)) - ==================================
2014-07-11 08:16:48,592 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405066083048_0648_000001_000000_00 is changed to TA_RUNNING
2014-07-11 08:16:48,608 INFO: BlockStateChange (logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48863 is added to blk_1073742863_2039{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-e6dc637a-af87-460c-801e-88558375725f:NORMAL|RBW]]} size 0
2014-07-11 08:16:48,610 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(115)) - Query status of ta_1405066083048_0648_000001_000000_00 is changed to TA_SUCCEEDED
2014-07-11 08:16:48,611 INFO: org.apache.tajo.worker.Task (run(467)) - Worker's task counter - total:1, succeeded: 1, killed: 1, failed: 0
2014-07-11 08:16:48,611 INFO: org.apache.tajo.worker.TaskRunner (run(346)) - Request GetTask: eb_1405066083048_0648_000001,container_1405066083048_0648_01_002571
2014-07-11 08:16:48,611 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1076)) - [eb_1405066083048_0648_000001] Task Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0)
2014-07-11 08:16:48,611 INFO: org.apache.tajo.master.querymaster.SubQuery (transition(1116)) - subQuery completed - eb_1405066083048_0648_000001 (total=1, success=1, killed=0)
2014-07-11 08:16:48,612 INFO: org.apache.tajo.master.DefaultTaskScheduler (stop(143)) - Task Scheduler stopped
2014-07-11 08:16:48,612 INFO: org.apache.tajo.master.DefaultTaskScheduler (run(102)) - TaskScheduler schedulingThread stopped
2014-07-11 08:16:48,612 INFO: org.apache.tajo.worker.TaskRunner (run(376)) - Received ShouldDie flag:eb_1405066083048_0648_000001,container_1405066083048_0648_01_002571
2014-07-11 08:16:48,612 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405066083048_0648 of type SUBQUERY_COMPLETED
2014-07-11 08:16:48,612 INFO: org.apache.tajo.master.querymaster.Query (handle(701)) - Processing q_1405066083048_0648 of type QUERY_COMPLETED
2014-07-11 08:16:48,612 INFO: org.apache.tajo.worker.TaskRunner (stop(239)) - Stop TaskRunner: eb_1405066083048_0648_000001
2014-07-11 08:16:48,613 INFO: org.apache.tajo.worker.TaskRunnerManager (stopTask(89)) - Stop Task:eb_1405066083048_0648_000001,container_1405066083048_0648_01_002571
2014-07-11 08:16:48,613 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.5,512
2014-07-11 08:16:48,613 INFO: org.apache.tajo.master.querymaster.Query (handle(718)) - q_1405066083048_0648 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-07-11 08:16:48,614 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(297)) - Query completion notified from q_1405066083048_0648
2014-07-11 08:16:48,614 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (handle(308)) - Query final state: QUERY_SUCCEEDED
2014-07-11 08:16:48,614 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(187)) - Stopping QueryMasterTask:q_1405066083048_0648
2014-07-11 08:16:48,614 INFO: org.apache.tajo.master.querymaster.QueryInProgress (heartbeat(265)) - Received QueryMaster heartbeat:q_1405066083048_0648,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf905.gq1.ygridcore.net
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.querymaster.QueryJobManager (stopQuery(203)) - Stop QueryInProgress:q_1405066083048_0648
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(116)) - =========================================================
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(117)) - Stop query:q_1405066083048_0648
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (releaseWorkerResource(519)) - Release Resource: 0.0,512
2014-07-11 08:16:48,615 WARN: org.apache.tajo.master.TajoAsyncDispatcher (stop(115)) - Interrupted Exception while stopping
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.rm.TajoWorkerResourceManager (stopQueryMaster(541)) - Released QueryMaster (q_1405066083048_0648) resource.
2014-07-11 08:16:48,616 INFO: org.apache.tajo.master.querymaster.QueryInProgress (stop(125)) - q_1405066083048_0648 QueryMaster stopped
2014-07-11 08:16:48,615 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:q_1405066083048_0648
2014-07-11 08:16:48,616 WARN: org.apache.tajo.master.TajoAsyncDispatcher (stop(115)) - Interrupted Exception while stopping
2014-07-11 08:16:48,616 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:QueryInProgress:q_1405066083048_0648
2014-07-11 08:16:48,616 INFO: org.apache.tajo.master.querymaster.QueryMasterTask (stop(217)) - Stopped QueryMasterTask:q_1405066083048_0648
2014-07-11 08:16:48,617 INFO: org.apache.tajo.master.querymaster.QueryMaster (cleanup(166)) - cleanup query resources : q_1405066083048_0648
2014-07-11 08:16:49,051 INFO: org.apache.tajo.worker.TajoWorkerClientService (closeQuery(231)) - Stop Query:q_1405066083048_0648
2014-07-11 08:16:49,054 INFO: org.apache.tajo.master.GlobalEngine (dropDatabase(788)) - database TestTajoJdbc is dropped.
2014-07-11 08:16:49,056 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session 2b2b2234-720a-42ef-a869-43d76607756a is removed.
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.185 sec
2014-07-11 08:16:49,063 INFO: org.apache.tajo.worker.TajoWorker (run(492)) - ============================================
2014-07-11 08:16:49,063 INFO: org.apache.tajo.worker.TajoWorker (run(493)) - TajoWorker received SIGINT Signal
2014-07-11 08:16:49,063 INFO: org.apache.tajo.worker.TajoWorker (run(494)) - ============================================
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.InternalParquetRecordWriter: Flushing mem store to file. allocated memory: 63,754,392
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_orderkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 3 entries, 12B raw, 3B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_partkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 3 entries, 12B raw, 3B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 43B for [l_suppkey] INT32: 5 values, 26B raw, 26B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_linenumber] INT32: 5 values, 9B raw, 9B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 2 entries, 8B raw, 2B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_quantity] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_extendedprice] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 63B for [l_discount] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_tax] DOUBLE: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 4 entries, 32B raw, 4B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_returnflag] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 2 entries, 10B raw, 2B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 26B for [l_linestatus] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 2 entries, 10B raw, 2B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_commitdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 95B for [l_receiptdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_shipinstruct] BINARY: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 3 entries, 49B raw, 3B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 27B for [l_shipmode] BINARY: 5 values, 10B raw, 10B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 4 entries, 32B raw, 4B comp}
Jul 11, 2014 8:13:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 190B for [l_comment] BINARY: 5 values, 171B raw, 171B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordWriter: Flushing mem store to file. allocated memory: 63,753,806
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_orderkey] INT32: 2 values, 8B raw, 8B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 1 entries, 4B raw, 1B comp}
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_partkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_suppkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 31B for [l_linenumber] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_quantity] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_extendedprice] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 39B for [l_discount] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_tax] DOUBLE: 2 values, 8B raw, 8B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 1 entries, 8B raw, 1B comp}
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_returnflag] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 1 entries, 5B raw, 1B comp}
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 25B for [l_linestatus] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings: [BIT_PACKED, PLAIN_DICTIONARY, RLE], dic { 1 entries, 5B raw, 1B comp}
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_shipdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_commitdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_receiptdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 51B for [l_shipinstruct] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 38B for [l_shipmode] BINARY: 2 values, 21B raw, 21B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written 90B for [l_comment] BINARY: 2 values, 71B raw, 71B comp, 1 pages, encodings: [BIT_PACKED, PLAIN, RLE]
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 2 records.
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block read in memory in 6 ms. row count = 2
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another 1 footers
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: RecordReader initialized will read a total of 2 records.
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at row 0. reading next block
Jul 11, 2014 8:13:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block read in memory in 1 ms. row count = 2
2014-07-11 08:16:49,071 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session 1c28c0f2-1cda-44d6-8fac-6211e8e0b511 is removed.
2014-07-11 08:16:49,071 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,072 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,071 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,072 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,072 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,075 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,071 ERROR: org.apache.tajo.rpc.RpcProtos (exceptionCaught(225)) - RPC Exception:Worker has already been shutdown
2014-07-11 08:16:49,075 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,075 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,075 INFO: org.apache.tajo.master.session.SessionManager (removeSession(80)) - Session 741f4d10-1b8d-42fa-84f7-bac93b8eb405 is removed.
2014-07-11 08:16:49,075 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,074 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,073 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,072 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,075 ERROR: org.apache.tajo.client.TajoClient (close(141)) - java.io.IOException: Connect error to localhost/127.0.0.1:18678 cause java.util.concurrent.RejectedExecutionException: Worker has already been shutdown
2014-07-11 08:16:49,087 INFO: org.apache.tajo.worker.WorkerHeartbeatService (run(260)) - Worker Resource Heartbeat Thread stopped.
2014-07-11 08:16:49,138 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (TajoWorkerProtocol) listened on 0:0:0:0:0:0:0:0:18682) shutdown
2014-07-11 08:16:49,144 INFO: org.apache.tajo.worker.TajoWorkerManagerService (stop(95)) - TajoWorkerManagerService stopped
2014-07-11 08:16:49,152 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterProtocol) listened on 0:0:0:0:0:0:0:0:18681) shutdown
2014-07-11 08:16:49,152 INFO: org.apache.tajo.master.querymaster.QueryMasterManagerService (stop(111)) - QueryMasterManagerService stopped
2014-07-11 08:16:49,153 INFO: org.apache.tajo.master.querymaster.QueryMaster (run(433)) - QueryMaster heartbeat thread stopped
2014-07-11 08:16:49,154 INFO: org.apache.tajo.master.TajoAsyncDispatcher (stop(122)) - AsyncDispatcher stopped:querymaster_1405066083681
2014-07-11 08:16:49,154 INFO: org.apache.tajo.master.querymaster.QueryMaster (stop(159)) - QueryMaster stop
2014-07-11 08:16:49,154 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(110)) - TajoWorkerClientService stopping
2014-07-11 08:16:49,156 INFO: org.apache.tajo.rpc.NettyServerBase (shutdown(128)) - Rpc (QueryMasterClientProtocol) listened on 0:0:0:0:0:0:0:0:18680) shutdown
2014-07-11 08:16:49,157 INFO: org.apache.tajo.worker.TajoWorkerClientService (stop(114)) - TajoWorkerClientService stopped
2014-07-11 08:16:49,157 INFO: org.apache.tajo.worker.TajoWorker (stop(334)) - TajoWorker main thread exiting
Results :
Failed tests: testGroupByWithConstantKeys2(org.apache.tajo.engine.query.TestGroupByQuery): Result Verification expected:<...-------------------(..)
Tests run: 1058, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 5.479 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 0.717 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.575 s]
[INFO] Tajo Common ....................................... SUCCESS [ 37.096 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 1.282 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.318 s]
[INFO] Tajo Rpc .......................................... SUCCESS [ 21.371 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.003 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 5.969 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 44.546 s]
[INFO] Tajo Core PullServer .............................. SUCCESS [ 0.789 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.909 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.454 s]
[INFO] Tajo Core ......................................... FAILURE [09:04 min]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 11:14 min
[INFO] Finished at: 2014-07-11T08:16:49+00:00
[INFO] Final Memory: 94M/1935M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on project tajo-core: There are test failures.
[ERROR]
[ERROR] Please refer to <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core/target/surefire-reports> for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core
Build step 'Execute shell' marked build as failure
Updating TAJO-852