See <https://builds.apache.org/job/Tajo-0.8.1-nightly/264/>
------------------------------------------
[...truncated 106786 lines...]
=> 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-12-11 02:06:40,265 INFO master.GlobalEngine
(GlobalEngine.java:createLogicalPlan(345)) -
=============================================
2014-12-11 02:06:40,265 INFO rewrite.BasicQueryRewriteEngine
(BasicQueryRewriteEngine.java:rewrite(64)) - The rule "FilterPushDown "
rewrites the query.
2014-12-11 02:06:40,266 INFO rewrite.BasicQueryRewriteEngine
(BasicQueryRewriteEngine.java:rewrite(64)) - The rule "ProjectionPushDown "
rewrites the query.
2014-12-11 02:06:40,266 INFO master.GlobalEngine
(GlobalEngine.java:createLogicalPlan(347)) -
=============================================
2014-12-11 02:06:40,266 INFO master.GlobalEngine
(GlobalEngine.java:createLogicalPlan(348)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND
default.lineitem.l_quantity (FLOAT8) > 20
=> 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-12-11 02:06:40,266 INFO master.GlobalEngine
(GlobalEngine.java:createLogicalPlan(349)) -
=============================================
2014-12-11 02:06:40,267 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:start(101)) - AsyncDispatcher
started:QueryInProgress:q_1418263349856_0284
2014-12-11 02:06:40,267 INFO querymaster.QueryInProgress
(QueryInProgress.java:startQueryMaster(156)) - Initializing QueryInProgress for
QueryID=q_1418263349856_0284
2014-12-11 02:06:40,267 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:allocateQueryMaster(205)) -
q_1418263349856_0284's QueryMaster is host:asf905.gq1.ygridcore.net,
port=28925,28926,28924,60085, slots=m:1024,d:2.0,c:1, used=m:512,d:0.0,c:0
2014-12-11 02:06:40,267 INFO master.GlobalEngine
(GlobalEngine.java:executeQueryInternal(270)) - Query is forwarded to
asf905.gq1.ygridcore.net:28925
2014-12-11 02:06:40,267 INFO querymaster.QueryInProgress
(QueryInProgress.java:connectQueryMaster(199)) - Connect to
QueryMaster:asf905.gq1.ygridcore.net/67.195.81.149:28925
2014-12-11 02:06:40,268 INFO querymaster.QueryInProgress
(QueryInProgress.java:submmitQueryToMaster(220)) - Call executeQuery to
:asf905.gq1.ygridcore.net:28925,q_1418263349856_0284
2014-12-11 02:06:40,270 INFO querymaster.QueryMasterManagerService
(QueryMasterManagerService.java:executeQuery(227)) - Receive executeQuery
request:q_1418263349856_0284
2014-12-11 02:06:40,271 INFO querymaster.QueryMaster
(QueryMaster.java:handle(378)) - Start
QueryStartEventHandler:q_1418263349856_0284
2014-12-11 02:06:40,276 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:initStagingDir(404)) - The staging dir
'hdfs://localhost:46058/tmp/tajo-jenkins/staging/q_1418263349856_0284' is
created.
2014-12-11 02:06:40,309 INFO rewrite.BasicQueryRewriteEngine
(BasicQueryRewriteEngine.java:rewrite(64)) - The rule "FilterPushDown "
rewrites the query.
2014-12-11 02:06:40,309 INFO rewrite.BasicQueryRewriteEngine
(BasicQueryRewriteEngine.java:rewrite(64)) - The rule "ProjectionPushDown "
rewrites the query.
2014-12-11 02:06:40,309 INFO global.GlobalPlanner
(GlobalPlanner.java:build(117)) -
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
-----------------------------
Optimization Log:
-----------------------------
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND
default.lineitem.l_quantity (FLOAT8) > 20
=> 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-12-11 02:06:40,310 INFO global.GlobalPlanner
(GlobalPlanner.java:build(155)) -
-------------------------------------------------------------------------------
Execution Block Graph (TERMINAL - eb_1418263349856_0284_000002)
-------------------------------------------------------------------------------
|-eb_1418263349856_0284_000002
|-eb_1418263349856_0284_000001
-------------------------------------------------------------------------------
=======================================================
Block Id: eb_1418263349856_0284_000001 [ROOT]
=======================================================
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_returnflag (TEXT) = R AND
default.lineitem.l_quantity (FLOAT8) > 20
=> 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_1418263349856_0284_000002 [TERMINAL]
=======================================================
2014-12-11 02:06:40,310 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:start(101)) - AsyncDispatcher
started:q_1418263349856_0284
2014-12-11 02:06:40,310 INFO querymaster.Query (Query.java:handle(682)) -
Processing q_1418263349856_0284 of type START
2014-12-11 02:06:40,311 INFO querymaster.SubQuery
(SubQuery.java:initTaskScheduler(673)) -
org.apache.tajo.master.DefaultTaskScheduler is chosen for the task scheduling
for eb_1418263349856_0284_000001
2014-12-11 02:06:40,314 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:listStatus(386)) - Total input paths to process : 1
2014-12-11 02:06:40,315 INFO storage.AbstractStorageManager
(AbstractStorageManager.java:getSplits(615)) - Total # of splits: 1
2014-12-11 02:06:40,315 INFO querymaster.SubQuery
(SubQuery.java:transition(643)) - 1 objects are scheduled
2014-12-11 02:06:40,316 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:start(88)) - Start TaskScheduler
2014-12-11 02:06:40,316 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:calculateNumRequestContainers(99)) -
CalculateNumberRequestContainer - Number of Tasks=1, Number of Cluster Slots=1
2014-12-11 02:06:40,316 INFO querymaster.SubQuery
(SubQuery.java:allocateContainers(880)) - Request Container for
eb_1418263349856_0284_000001 containers=1
2014-12-11 02:06:40,316 INFO querymaster.Query (Query.java:handle(699)) -
q_1418263349856_0284 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2014-12-11 02:06:40,317 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(216)) - Start TajoWorkerAllocationThread
2014-12-11 02:06:40,318 INFO worker.TajoResourceAllocator
(TajoResourceAllocator.java:run(332)) - Stop TajoWorkerAllocationThread
2014-12-11 02:06:40,318 INFO querymaster.SubQuery
(SubQuery.java:transition(988)) - SubQuery (eb_1418263349856_0284_000001) has 1
containers!
2014-12-11 02:06:40,320 INFO worker.TaskRunner (TaskRunner.java:<init>(123)) -
Tajo Root Dir: hdfs://localhost:46058/tajo
2014-12-11 02:06:40,320 INFO worker.TaskRunner (TaskRunner.java:<init>(124)) -
Worker Local Dir:
file://<https://builds.apache.org/job/Tajo-0.8.1-nightly/ws/tajo-core/target/test-data/625bfc23-d238-4cdf-a8e7-ab0477e42378/tajo-localdir>
2014-12-11 02:06:40,320 INFO worker.TaskRunner (TaskRunner.java:<init>(138)) -
QueryMaster Address:asf905.gq1.ygridcore.net/67.195.81.149:28925
2014-12-11 02:06:40,320 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:run(188)) - Start
TaskRunner:eb_1418263349856_0284_000001,container_1418263349856_0284_01_000739
2014-12-11 02:06:40,321 INFO worker.TaskRunner (TaskRunner.java:init(185)) -
TaskRunner basedir is created (q_1418263349856_0284/output/1)
2014-12-11 02:06:40,321 INFO worker.TaskRunner (TaskRunner.java:run(312)) -
TaskRunner startup
2014-12-11 02:06:40,322 INFO worker.TaskRunner (TaskRunner.java:run(332)) -
Request GetTask:
eb_1418263349856_0284_000001,container_1418263349856_0284_01_000739
2014-12-11 02:06:40,323 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:allocateRackTask(709)) - Assigned Local/Rack/Total:
(0/1/1), Locality: 0.00%, Rack host: 67.195.81.149
2014-12-11 02:06:40,324 INFO worker.TaskRunner (TaskRunner.java:run(370)) -
Accumulated Received Task: 1
2014-12-11 02:06:40,324 INFO worker.TaskRunner (TaskRunner.java:run(379)) -
Initializing: ta_1418263349856_0284_000001_000000_00
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(183)) - Output File
Path:
hdfs://localhost:46058/tmp/tajo-jenkins/staging/q_1418263349856_0284/RESULT/part-01-000000
2014-12-11 02:06:40,326 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1418263349856_0284_000001_000000_00 is changed to TA_PENDING
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(188)) -
==================================
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(189)) - * Subquery
ta_1418263349856_0284_000001_000000_00 is initialized
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(190)) - *
InterQuery: false
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(193)) - * Fragments
(num: 1)
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(194)) - * Fetches
(total:0) :
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(198)) - * Local
task dir:
<https://builds.apache.org/job/Tajo-0.8.1-nightly/ws/tajo-core/target/test-data/625bfc23-d238-4cdf-a8e7-ab0477e42378/tajo-localdir/q_1418263349856_0284/output/1/0_0>
2014-12-11 02:06:40,326 INFO worker.Task (Task.java:<init>(203)) -
==================================
2014-12-11 02:06:40,327 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1418263349856_0284_000001_000000_00 is changed to TA_RUNNING
2014-12-11 02:06:40,340 INFO BlockStateChange
(BlockManager.java:logAddStoredBlock(2300)) - BLOCK* addStoredBlock: blockMap
updated: 127.0.0.1:48837 is added to
blk_1073742210_1386{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1,
replicas=[ReplicaUnderConstruction[[DISK]DS-d7419c71-5749-4dca-b749-fd1c69c723b1:NORMAL|RBW]]}
size 0
2014-12-11 02:06:40,341 INFO worker.TaskAttemptContext
(TaskAttemptContext.java:setState(110)) - Query status of
ta_1418263349856_0284_000001_000000_00 is changed to TA_SUCCEEDED
2014-12-11 02:06:40,342 INFO worker.Task (Task.java:run(447)) - Task Counter -
total:675, succeeded: 675, killed: 0, failed: 0
2014-12-11 02:06:40,342 INFO worker.TaskRunner (TaskRunner.java:run(332)) -
Request GetTask:
eb_1418263349856_0284_000001,container_1418263349856_0284_01_000739
2014-12-11 02:06:40,342 INFO querymaster.SubQuery
(SubQuery.java:transition(1065)) - [eb_1418263349856_0284_000001] Task
Completion Event (Total: 1, Success: 1, Killed: 0, Failed: 0
2014-12-11 02:06:40,343 INFO querymaster.SubQuery
(SubQuery.java:transition(1105)) - subQuery completed -
eb_1418263349856_0284_000001 (total=1, success=1, killed=0)
2014-12-11 02:06:40,343 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:stop(144)) - Task Scheduler stopped
2014-12-11 02:06:40,343 INFO master.DefaultTaskScheduler
(DefaultTaskScheduler.java:run(103)) - TaskScheduler schedulingThread stopped
2014-12-11 02:06:40,343 INFO worker.TaskRunner (TaskRunner.java:run(362)) -
Received ShouldDie
flag:eb_1418263349856_0284_000001,container_1418263349856_0284_01_000739
2014-12-11 02:06:40,343 INFO worker.TaskRunner (TaskRunner.java:stop(227)) -
Stop TaskRunner: eb_1418263349856_0284_000001
2014-12-11 02:06:40,343 INFO querymaster.Query (Query.java:handle(682)) -
Processing q_1418263349856_0284 of type SUBQUERY_COMPLETED
2014-12-11 02:06:40,344 INFO worker.TaskRunnerManager
(TaskRunnerManager.java:stopTask(89)) - Stop
Task:eb_1418263349856_0284_000001,container_1418263349856_0284_01_000739
2014-12-11 02:06:40,344 INFO querymaster.Query (Query.java:handle(682)) -
Processing q_1418263349856_0284 of type QUERY_COMPLETED
2014-12-11 02:06:40,344 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:releaseWorkerResource(604)) - Release
Resource:eb_1418263349856_0284_000001,0.5,512
2014-12-11 02:06:40,345 INFO querymaster.Query (Query.java:handle(699)) -
q_1418263349856_0284 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2014-12-11 02:06:40,345 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:handle(278)) - Query completion notified from
q_1418263349856_0284
2014-12-11 02:06:40,345 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:handle(289)) - Query final state: QUERY_SUCCEEDED
2014-12-11 02:06:40,346 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:stop(182)) - Stopping QueryMasterTask:q_1418263349856_0284
2014-12-11 02:06:40,346 INFO querymaster.QueryJobManager
(QueryJobManager.java:stopQuery(147)) - Stop
QueryInProgress:q_1418263349856_0284
2014-12-11 02:06:40,346 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(109)) -
=========================================================
2014-12-11 02:06:40,347 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(110)) - Stop query:q_1418263349856_0284
2014-12-11 02:06:40,346 INFO querymaster.QueryInProgress
(QueryInProgress.java:heartbeat(252)) - Received QueryMaster
heartbeat:q_1418263349856_0284state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=host:asf905.gq1.ygridcore.net, port=28925,28926,28924,0,
slots=m:0,d:0.0,c:0, used=m:0,d:0.0,c:0
2014-12-11 02:06:40,347 INFO rm.TajoWorkerResourceManager
(TajoWorkerResourceManager.java:stopQueryMaster(644)) - release QueryMaster
resource:q_1418263349856_0284,host:asf905.gq1.ygridcore.net,
port=28925,28926,28924,60085, slots=m:1024,d:2.0,c:1, used=m:0,d:0.0,c:0
2014-12-11 02:06:40,347 INFO querymaster.QueryInProgress
(QueryInProgress.java:stop(118)) - q_1418263349856_0284 QueryMaster stopped
2014-12-11 02:06:40,349 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:QueryInProgress:q_1418263349856_0284
2014-12-11 02:06:40,349 WARN master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(115)) - Interrupted Exception while stopping
2014-12-11 02:06:40,349 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:q_1418263349856_0284
2014-12-11 02:06:40,350 INFO querymaster.QueryMasterTask
(QueryMasterTask.java:stop(210)) - Stopped QueryMasterTask:q_1418263349856_0284
2014-12-11 02:06:40,783 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:closeQuery(217)) - Stop Query:q_1418263349856_0284
2014-12-11 02:06:40,786 INFO master.GlobalEngine
(GlobalEngine.java:dropDatabase(607)) - database TestTajoJdbc is dropped.
2014-12-11 02:06:40,787 INFO session.SessionManager
(SessionManager.java:removeSession(80)) - Session
105e3108-36b7-4e54-ac56-393fd2cc27be is removed.
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.694 sec
2014-12-11 02:06:40,793 INFO worker.TajoWorker (TajoWorker.java:run(687)) -
============================================
2014-12-11 02:06:40,793 INFO worker.TajoWorker (TajoWorker.java:run(688)) -
TajoWorker received SIGINT Signal
2014-12-11 02:06:40,793 INFO worker.TajoWorker (TajoWorker.java:run(689)) -
============================================
2014-12-11 02:06:40,795 INFO worker.TajoWorker (TajoWorker.java:run(661)) -
Worker Resource Heartbeat Thread stopped.
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 63,754,392
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [l_orderkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 3 entries, 12B raw, 3B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [l_partkey] INT32: 5 values, 10B raw, 10B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 3 entries, 12B raw, 3B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
43B for [l_suppkey] INT32: 5 values, 26B raw, 26B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
26B for [l_linenumber] INT32: 5 values, 9B raw, 9B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 2 entries, 8B raw, 2B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
63B for [l_quantity] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
63B for [l_extendedprice] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages,
encodings: [RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
63B for [l_discount] DOUBLE: 5 values, 46B raw, 46B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [l_tax] DOUBLE: 5 values, 10B raw, 10B comp, 1 pages, encodings: [RLE,
PLAIN_DICTIONARY, BIT_PACKED], dic { 4 entries, 32B raw, 4B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
26B for [l_returnflag] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 2 entries, 10B raw, 2B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
26B for [l_linestatus] BINARY: 5 values, 9B raw, 9B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 2 entries, 10B raw, 2B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
95B for [l_shipdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
95B for [l_commitdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
95B for [l_receiptdate] BINARY: 5 values, 76B raw, 76B comp, 1 pages,
encodings: [RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [l_shipinstruct] BINARY: 5 values, 10B raw, 10B comp, 1 pages,
encodings: [RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 3 entries, 49B raw, 3B
comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [l_shipmode] BINARY: 5 values, 10B raw, 10B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 4 entries, 32B raw, 4B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
190B for [l_comment] BINARY: 5 values, 171B raw, 171B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 63,753,806
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
25B for [l_orderkey] INT32: 2 values, 8B raw, 8B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 4B raw, 1B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [l_partkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [l_suppkey] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [l_linenumber] INT32: 2 values, 14B raw, 14B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
39B for [l_quantity] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
39B for [l_extendedprice] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages,
encodings: [RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
39B for [l_discount] DOUBLE: 2 values, 22B raw, 22B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
25B for [l_tax] DOUBLE: 2 values, 8B raw, 8B comp, 1 pages, encodings: [RLE,
PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 8B raw, 1B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
25B for [l_returnflag] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 5B raw, 1B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
25B for [l_linestatus] BINARY: 2 values, 8B raw, 8B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 5B raw, 1B comp}
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
51B for [l_shipdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
51B for [l_commitdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
51B for [l_receiptdate] BINARY: 2 values, 34B raw, 34B comp, 1 pages,
encodings: [RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
51B for [l_shipinstruct] BINARY: 2 values, 34B raw, 34B comp, 1 pages,
encodings: [RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
38B for [l_shipmode] BINARY: 2 values, 21B raw, 21B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:23 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
90B for [l_comment] BINARY: 2 values, 71B raw, 71B comp, 1 pages, encodings:
[RLE, PLAIN, BIT_PACKED]
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 2 records.
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 8 ms. row count = 2
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 2 records.
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Dec 11, 2014 2:04:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 1 ms. row count = 2
2014-12-11 02:06:40,798 INFO session.SessionManager
(SessionManager.java:removeSession(80)) - Session
c02e7bed-4563-4884-9ca8-2c9dc0b44338 is removed.
2014-12-11 02:06:40,798 INFO session.SessionManager
(SessionManager.java:removeSession(80)) - Session
f7cf3f30-6785-4b70-927e-42ab7302a9f7 is removed.
2014-12-11 02:06:40,841 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(127)) - Rpc (TajoWorkerProtocol) listened on
0:0:0:0:0:0:0:0:28926) shutdown
2014-12-11 02:06:40,842 INFO worker.TajoWorkerManagerService
(TajoWorkerManagerService.java:stop(95)) - TajoWorkerManagerService stopped
2014-12-11 02:06:40,851 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterProtocol) listened on
0:0:0:0:0:0:0:0:28925) shutdown
2014-12-11 02:06:40,851 INFO querymaster.QueryMasterManagerService
(QueryMasterManagerService.java:stop(111)) - QueryMasterManagerService stopped
2014-12-11 02:06:40,852 INFO querymaster.QueryMaster
(QueryMaster.java:run(437)) - QueryMaster heartbeat thread stopped
2014-12-11 02:06:40,853 INFO master.TajoAsyncDispatcher
(TajoAsyncDispatcher.java:stop(122)) - AsyncDispatcher
stopped:querymaster_1418263351183
2014-12-11 02:06:40,854 INFO querymaster.QueryMaster
(QueryMaster.java:stop(160)) - QueryMaster stop
2014-12-11 02:06:40,854 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:stop(107)) - TajoWorkerClientService stopping
2014-12-11 02:06:40,857 INFO rpc.NettyServerBase
(NettyServerBase.java:shutdown(127)) - Rpc (QueryMasterClientProtocol) listened
on 0:0:0:0:0:0:0:0:28924) shutdown
2014-12-11 02:06:40,857 INFO worker.TajoWorkerClientService
(TajoWorkerClientService.java:stop(111)) - TajoWorkerClientService stopped
2014-12-11 02:06:40,857 INFO worker.TajoWorker (TajoWorker.java:stop(352)) -
TajoWorker main thread exiting
Results :
Failed tests: testKillQuery(org.apache.tajo.client.TestTajoClient):
expected:<QUERY_KILLED> but was:<QUERY_KILL_WAIT>
testGetFinishedQueryList(org.apache.tajo.client.TestTajoClient): expected:<2>
but was:<3>
Tests in error:
testGetQueryStatusAndResultAfterFinish(org.apache.tajo.client.TestTajoClient):
test timed out after 20000 milliseconds
Tests run: 711, Failures: 2, Errors: 1, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 4.309 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 0.727 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 2.621 s]
[INFO] Tajo Common ....................................... SUCCESS [ 6.757 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 1.167 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 5.361 s]
[INFO] Tajo Rpc .......................................... SUCCESS [ 21.201 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 0.994 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 5.507 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 44.450 s]
[INFO] Tajo Yarn PullServer .............................. SUCCESS [ 0.708 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.984 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 0.467 s]
[INFO] Tajo Catalog Drivers HCatalog ..................... SUCCESS [ 9.572 s]
[INFO] Tajo Core Backend ................................. FAILURE [04:30 min]
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 06:17 min
[INFO] Finished at: 2014-12-11T02:06:41+00:00
[INFO] Final Memory: 82M/1111M
[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-0.8.1-nightly/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
Recording test results