You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tajo.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/09/02 07:02:05 UTC
Build failed in Jenkins: Tajo-master-build #822
See <https://builds.apache.org/job/Tajo-master-build/822/changes>
Changes:
[jihoonson] TAJO-1808: Wrong table type problem in catalog.
------------------------------------------
[...truncated 340156 lines...]
2015-09-02 05:03:18,474 INFO: org.apache.tajo.querymaster.Stage (transition(1303)) - Stage - eb_1441169748761_1043_000006 finalize HASH_SHUFFLE (total=1, success=1, killed=0)
2015-09-02 05:03:18,474 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-02 05:03:18,474 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(122)) - TaskScheduler schedulingThread stopped
2015-09-02 05:03:18,475 INFO: org.apache.tajo.querymaster.Stage (transition(1314)) - eb_1441169748761_1043_000006, wait for HASH_SHUFFLE reports. expected Tasks:1
2015-09-02 05:03:18,475 INFO: org.apache.tajo.storage.HashShuffleAppenderManager (close(155)) - Close HashShuffleAppender:eb_1441169748761_1043_000006, intermediates=1
2015-09-02 05:03:18,476 INFO: org.apache.tajo.querymaster.Stage (finalizeShuffleReport(1260)) - eb_1441169748761_1043_000006, Finalized HASH_SHUFFLE reports: 1
2015-09-02 05:03:18,476 INFO: org.apache.tajo.querymaster.Stage (transition(1361)) - Stage completed - eb_1441169748761_1043_000006 (total=1, success=1, killed=0)
2015-09-02 05:03:18,476 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441169748761_1043 of type STAGE_COMPLETED
2015-09-02 05:03:18,476 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1441169748761_1043_000007
2015-09-02 05:03:18,476 INFO: org.apache.tajo.querymaster.Query (executeNextBlock(757)) - Scheduling Stage:eb_1441169748761_1043_000007
2015-09-02 05:03:18,476 INFO: org.apache.tajo.querymaster.Stage (initTaskScheduler(888)) - org.apache.tajo.querymaster.DefaultTaskScheduler is chosen for the task scheduling for eb_1441169748761_1043_000007
2015-09-02 05:03:18,477 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleFragmentsForJoinQuery(261)) - [Distributed Join Strategy] : Symmetric Repartition Join
2015-09-02 05:03:18,477 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(357)) - Larger intermediate data is approximately 1 MB
2015-09-02 05:03:18,477 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(360)) - The calculated number of tasks is 1
2015-09-02 05:03:18,477 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(361)) - The number of total shuffle keys is 1
2015-09-02 05:03:18,477 INFO: org.apache.tajo.querymaster.Repartitioner (scheduleSymmetricRepartitionJoin(365)) - The determined number of join tasks is 1
2015-09-02 05:03:18,477 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1441169748761_1043_000006
2015-09-02 05:03:18,478 INFO: org.apache.tajo.querymaster.Stage (run(840)) - 1 objects are scheduled
2015-09-02 05:03:18,478 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (start(130)) - Start TaskScheduler
2015-09-02 05:03:18,480 INFO: org.apache.tajo.worker.TaskManager (createExecutionBlock(112)) - QueryMaster Address:asf905.gq1.ygridcore.net:19047
2015-09-02 05:03:18,482 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(119)) - Tajo Root Dir: hdfs://localhost:52060/tajo
2015-09-02 05:03:18,482 INFO: org.apache.tajo.worker.ExecutionBlockContext (init(120)) - Worker Local Dir: file://<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir>
2015-09-02 05:03:18,482 INFO: org.apache.tajo.worker.TaskManager (handle(182)) - Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000, Disks:3, vCores:2)
2015-09-02 05:03:18,483 INFO: org.apache.tajo.worker.TaskImpl (<init>(114)) - Task basedir is created (<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/output/7)>
2015-09-02 05:03:18,483 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441169748761_1043_000007_000000_00 is changed to TA_PENDING
2015-09-02 05:03:18,483 INFO: org.apache.tajo.worker.TaskImpl (init(195)) - Initializing: ta_1441169748761_1043_000007_000000_00
2015-09-02 05:03:18,484 INFO: org.apache.tajo.storage.FileTablespace (getAppenderFilePath(294)) - Output File Path: hdfs://localhost:52060/tmp/tajo-jenkins/staging/q_1441169748761_1043/RESULT/part-07-000000-000
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) - Output File Path: hdfs://localhost:52060/tmp/tajo-jenkins/staging/q_1441169748761_1043/RESULT/part-07-000000-000
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) - ==================================
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) - * Stage ta_1441169748761_1043_000007_000000_00 is initialized
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) - * InterQuery: false, Fragments (num: 4), Fetches (total:2) :
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(162)) - * Local task dir: <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/output/7/0_0>
2015-09-02 05:03:18,484 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) - ==================================
2015-09-02 05:03:18,485 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/in/eb_1441169748761_1043_000007/0/0/eb_1441169748761_1043_000006>
2015-09-02 05:03:18,485 INFO: org.apache.tajo.worker.TaskImpl (init(214)) - the directory is created <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/in/eb_1441169748761_1043_000007/0/0/eb_1441169748761_1043_000004>
2015-09-02 05:03:18,486 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-02 05:03:18,486 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-02 05:03:18,486 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=h, sid=6, partId=0, taskIds=null
2015-09-02 05:03:18,487 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=40, fromRemote=false, ebId=eb_1441169748761_1043_000006) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/output/6/hash-shuffle/0/0>
2015-09-02 05:03:18,487 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(692)) - Try to get local file chunk at local host
2015-09-02 05:03:18,487 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(734)) - getLocalStoredFileChunk starts
2015-09-02 05:03:18,487 INFO: org.apache.tajo.worker.TaskImpl (getLocalStoredFileChunk(769)) - PullServer request param: shuffleType=h, sid=4, partId=0, taskIds=null
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.TaskImpl (getFetchRunners(720)) - Create a new Fetcher with storeChunk: (start=0, length=51, fromRemote=false, ebId=eb_1441169748761_1043_000004) <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/test-data/fba4453c-a9b4-4928-aa64-cd7dbb315ea1/tajo-localdir/q_1441169748761_1043/output/4/hash-shuffle/0/0>
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441169748761_1043_000007_000000_00 is changed to TA_RUNNING
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.Fetcher (get(128)) - Get pseudo fetch from local host
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.TaskImpl (run(616)) - Add a new FileChunk to local chunk list
2015-09-02 05:03:18,488 INFO: org.apache.tajo.worker.TaskImpl (waitForFetch(362)) - ta_1441169748761_1043_000007_000000_00 All fetches are done!
2015-09-02 05:03:18,489 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-02 05:03:18,489 INFO: org.apache.tajo.worker.TaskImpl (localizeFetchedData(572)) - One local chunk is added to listTablets
2015-09-02 05:03:18,490 INFO: org.apache.tajo.engine.planner.PhysicalPlannerImpl (createLeftSemiJoinPlan(675)) - Left Semi Join (15) chooses [In Memory Hash Join].
2015-09-02 05:03:18,499 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744609_3785{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b1091ff6-a5f3-44f2-845a-1efb51c20a97:NORMAL:127.0.0.1:60720|RBW]]} size 27
2015-09-02 05:03:18,644 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(358)) - Saving query summary: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1040/query.hist
2015-09-02 05:03:18,651 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744610_3786{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:18,653 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1040/eb_1441169748761_1040_000003.hist
2015-09-02 05:03:18,658 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744611_3787{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b1091ff6-a5f3-44f2-845a-1efb51c20a97:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:18,660 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1040/eb_1441169748761_1040_000007.hist
2015-09-02 05:03:18,665 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744612_3788{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:18,667 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1040/eb_1441169748761_1040_000005.hist
2015-09-02 05:03:18,670 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744613_3789{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|RBW]]} size 784
2015-09-02 05:03:18,901 INFO: org.apache.tajo.worker.TaskAttemptContext (setState(142)) - Query status of ta_1441169748761_1043_000007_000000_00 is changed to TA_SUCCEEDED
2015-09-02 05:03:18,901 INFO: org.apache.tajo.worker.TaskImpl (run(460)) - ta_1441169748761_1043_000007_000000_00 completed. Worker's task counter - total:1, succeeded: 1, killed: 0, failed: 0
2015-09-02 05:03:18,902 INFO: org.apache.tajo.querymaster.Stage (transition(1303)) - Stage - eb_1441169748761_1043_000007 finalize NONE_SHUFFLE (total=1, success=1, killed=0)
2015-09-02 05:03:18,902 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (stop(160)) - Task Scheduler stopped
2015-09-02 05:03:18,902 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler (run(122)) - TaskScheduler schedulingThread stopped
2015-09-02 05:03:18,903 INFO: org.apache.tajo.querymaster.Stage (transition(1361)) - Stage completed - eb_1441169748761_1043_000007 (total=1, success=1, killed=0)
2015-09-02 05:03:18,903 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441169748761_1043 of type STAGE_COMPLETED
2015-09-02 05:03:18,903 INFO: org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next executable block eb_1441169748761_1043_000008
2015-09-02 05:03:18,903 INFO: org.apache.tajo.querymaster.Query (transition(802)) - Complete Stage[eb_1441169748761_1043_000007], State: SUCCEEDED, 5/5.
2015-09-02 05:03:18,903 INFO: org.apache.tajo.querymaster.Query (handle(855)) - Processing q_1441169748761_1043 of type QUERY_COMPLETED
2015-09-02 05:03:18,903 INFO: org.apache.tajo.worker.TaskManager (stopExecutionBlock(161)) - Stopped execution block:eb_1441169748761_1043_000007
2015-09-02 05:03:18,904 INFO: org.apache.tajo.querymaster.Query (handle(873)) - q_1441169748761_1043 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-09-02 05:03:18,904 INFO: org.apache.tajo.querymaster.QueryMasterTask (handle(292)) - Query completion notified from q_1441169748761_1043 final state: QUERY_SUCCEEDED
2015-09-02 05:03:18,905 INFO: org.apache.tajo.master.QueryInProgress (heartbeat(253)) - Received QueryMaster heartbeat:q_1441169748761_1043,state=QUERY_SUCCEEDED,progress=1.0, queryMaster=asf905.gq1.ygridcore.net
2015-09-02 05:03:18,905 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(169)) - Stopping QueryMasterTask:q_1441169748761_1043
2015-09-02 05:03:18,905 INFO: org.apache.tajo.master.QueryManager (stopQuery(276)) - Stop QueryInProgress:q_1441169748761_1043
2015-09-02 05:03:18,906 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(118)) - =========================================================
2015-09-02 05:03:18,906 INFO: org.apache.tajo.querymaster.QueryMasterTask (cleanupQuery(469)) - Cleanup resources of all workers. Query: q_1441169748761_1043, workers: 1
2015-09-02 05:03:18,906 INFO: org.apache.tajo.master.QueryInProgress (stopProgress(119)) - Stop query:q_1441169748761_1043
2015-09-02 05:03:18,906 INFO: org.apache.tajo.querymaster.QueryMasterTask (serviceStop(185)) - Stopped QueryMasterTask:q_1441169748761_1043
2015-09-02 05:03:19,073 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(358)) - Saving query summary: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1041/query.hist
2015-09-02 05:03:19,079 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744614_3790{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:19,081 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1041/eb_1441169748761_1041_000002.hist
2015-09-02 05:03:19,085 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744615_3791{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b1091ff6-a5f3-44f2-845a-1efb51c20a97:NORMAL:127.0.0.1:60720|FINALIZED]]} size 0
2015-09-02 05:03:19,087 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1041/eb_1441169748761_1041_000004.hist
2015-09-02 05:03:19,089 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744616_3792{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:19,091 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(358)) - Saving query summary: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1042/query.hist
2015-09-02 05:03:19,106 INFO: org.apache.tajo.storage.FileTablespace (listStatus(368)) - Total input paths to process : 1
2015-09-02 05:03:19,106 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744617_3793{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b1091ff6-a5f3-44f2-845a-1efb51c20a97:NORMAL:127.0.0.1:60720|RBW]]} size 0
2015-09-02 05:03:19,107 INFO: org.apache.tajo.storage.FileTablespace (getSplits(572)) - Total # of splits: 1
2015-09-02 05:03:19,108 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1042/eb_1441169748761_1042_000004.hist
2015-09-02 05:03:19,111 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 36ce498c-ff14-49fb-8ce3-6086c138118c,q_1441169748761_1043, 3 rows
2015-09-02 05:03:19,112 INFO: org.apache.tajo.master.TajoMasterClientService (getQueryResultData(579)) - Send result to client for 36ce498c-ff14-49fb-8ce3-6086c138118c,q_1441169748761_1043, 0 rows
2015-09-02 05:03:19,112 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744618_3794{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-62564838-0b3c-43da-a8ae-cf3583c66507:NORMAL:127.0.0.1:60720|FINALIZED]]} size 0
Run: testInSubQueryWithJoin[2] Used memory: 563 MBytes, Active Threads:242
2015-09-02 05:03:19,115 INFO: org.apache.tajo.util.history.HistoryWriter (writeQueryHistory(372)) - Saving query unit: hdfs://localhost:52060/tmp/tajo-jenkins/staging/history/20150902/query-detail/q_1441169748761_1042/eb_1441169748761_1042_000002.hist
2015-09-02 05:03:19,115 INFO: org.apache.tajo.master.GlobalEngine (executeQuery(176)) - Query: select n_name from nation, supplier where n_regionkey in (select r_regionkey from region) and n_nationkey = s_nationkey
2015-09-02 05:03:19,120 INFO: BlockStateChange (logAddStoredBlock(2624)) - BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:60720 is added to blk_1073744619_3795{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b1091ff6-a5f3-44f2-845a-1efb51c20a97:NORMAL:127.0.0.1:60720|RBW]]} size 474
2015-09-02 05:03:19,124 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(280)) - Non Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
|-#QB_0
-----------------------------
Optimization Log:
-----------------------------
PROJECTION(6)
=> Targets: default.nation.n_name (TEXT)
=> out schema: {(1) default.nation.n_name (TEXT)}
=> in schema: {(12) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT), default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT), ?and (BOOLEAN)}
SELECTION(5)
=> Search Cond: (default.nation.n_regionkey (INT4) IN (Inline view (name=default.#SQ_0)) AND default.nation.n_nationkey (INT4) = default.supplier.s_nationkey (INT4))
JOIN(7)(CROSS)
=> target list: default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT), default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT), (default.nation.n_regionkey (INT4) IN (Inline view (name=default.#SQ_0)) AND default.nation.n_nationkey (INT4) = default.supplier.s_nationkey (INT4)) as ?and
=> out schema: {(12) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT), default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT), ?and (BOOLEAN)}
=> in schema: {(11) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT), default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT)}
SCAN(4) on default.supplier
=> target list: default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT)
=> out schema: {(7) default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT)}
=> in schema: {(7) default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT)}
SCAN(3) on default.nation
=> target list: default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT)
=> out schema: {(4) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT)}
=> in schema: {(4) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT)}
2015-09-02 05:03:19,127 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(282)) - =============================================
2015-09-02 05:03:19,127 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(283)) - Optimized Query:
-----------------------------
Query Block Graph
-----------------------------
|-#ROOT
|-#QB_0
-----------------------------
Optimization Log:
[LogicalPlan]
> IN subquery is rewritten into semi join.
> ProjectionNode is eliminated.
> ProjectionNode is eliminated.
[#ROOT]
> Non-optimized join order: ((default.nation âθ default.supplier) â default.#SQ_0) (cost: 3.6250395885000005E7)
> Optimized join order : ((default.nation âθ default.supplier) â default.#SQ_0) (cost: 8.115131134125002E7)
-----------------------------
JOIN(12)(LEFT_SEMI)
=> Join Cond: default.nation.n_regionkey (INT4) = default.#SQ_0.r_regionkey (INT4)
=> target list: default.nation.n_name (TEXT)
=> out schema: {(1) default.nation.n_name (TEXT)}
=> in schema: {(3) default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.#SQ_0.r_regionkey (INT4)}
TABLE_SUBQUERY(2) as default.#SQ_0
=> Targets: default.#SQ_0.r_regionkey (INT4)
=> out schema: {(1) default.#SQ_0.r_regionkey (INT4)}
=> in schema: {(1) default.#SQ_0.r_regionkey (INT4)}
GROUP_BY(10)(r_regionkey)
=> target list: default.region.r_regionkey (INT4)
=> out schema:{(1) default.region.r_regionkey (INT4)}
=> in schema:{(1) default.region.r_regionkey (INT4)}
SCAN(0) on default.region
=> target list: default.region.r_regionkey (INT4)
=> out schema: {(1) default.region.r_regionkey (INT4)}
=> in schema: {(3) default.region.r_regionkey (INT4), default.region.r_name (TEXT), default.region.r_comment (TEXT)}
JOIN(11)(INNER)
=> Join Cond: default.nation.n_nationkey (INT4) = default.supplier.s_nationkey (INT4)
=> target list: default.nation.n_name (TEXT), default.nation.n_regionkey (INT4)
=> out schema: {(2) default.nation.n_name (TEXT), default.nation.n_regionkey (INT4)}
=> in schema: {(4) default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_nationkey (INT4), default.supplier.s_nationkey (INT4)}
SCAN(4) on default.supplier
=> target list: default.supplier.s_nationkey (INT4)
=> out schema: {(1) default.supplier.s_nationkey (INT4)}
=> in schema: {(7) default.supplier.s_suppkey (INT4), default.supplier.s_name (TEXT), default.supplier.s_address (TEXT), default.supplier.s_nationkey (INT4), default.supplier.s_phone (TEXT), default.supplier.s_acctbal (FLOAT8), default.supplier.s_comment (TEXT)}
SCAN(3) on default.nation
=> target list: default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_nationkey (INT4)
=> out schema: {(3) default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_nationkey (INT4)}
=> in schema: {(4) default.nation.n_nationkey (INT4), default.nation.n_name (TEXT), default.nation.n_regionkey (INT4), default.nation.n_comment (TEXT)}
2015-09-02 05:03:19,128 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(284)) - =============================================
2015-09-02 05:03:19,128 INFO: org.apache.tajo.master.exec.QueryExecutor (executeDistributedQuery(512)) - Query q_1441169748761_1044,select n_name from nation, supplier where n_regionkey in (select r_regionkey from region) and n_nationkey = s_nationkey, is forwarded to :0
2015-09-02 05:03:19,128 INFO: org.apache.tajo.master.QueryInProgress (connectQueryMaster(184)) - Try to connect to QueryMaster:asf905.gq1.ygridcore.net/67.195.81.149:19047
2015-09-02 05:03:19,129 INFO: org.apache.tajo.master.QueryInProgress (allocateToQueryMaster(163)) - Initializing QueryInProgress for QueryID=q_1441169748761_1044
2015-09-02 05:03:19,129 INFO: org.apache.tajo.master.scheduler.SimpleScheduler (run(384)) - Running Queries: 1
2015-09-02 05:03:19,129 INFO: org.apache.tajo.master.QueryInProgress (submitToQueryMaster(206)) - Call executeQuery to :asf905.gq1.ygridcore.net:19047,q_1441169748761_1044
2015-09-02 05:03:19,132 INFO: org.apache.tajo.querymaster.QueryMasterManagerService (executeQuery(235)) - Receive executeQuery request:q_1441169748761_1044
2015-09-02 05:03:19,132 INFO: org.apache.tajo.querymaster.QueryMaster (handle(359)) - Start QueryStartEventHandler:q_1441169748761_1044
2015-09-02 05:03:19,132 INFO: org.apache.tajo.querymaster.QueryMasterTask (startQuery(314)) - INDEX_ENABLED : false
Killed
Results :
Tests run: 480, Failures: 0, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 1.928 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.277 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.070 s]
[INFO] Tajo Common ....................................... SUCCESS [ 30.958 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.448 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.752 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.117 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.279 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 47.219 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.485 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 10.940 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 9.555 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 52.086 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.031 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.362 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 1.749 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 1.585 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 3.806 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.307 s]
[INFO] Tajo Core ......................................... SUCCESS [ 10.330 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.936 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 11.484 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.052 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 0.983 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.070 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 3.683 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.399 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 28.222 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 0.987 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.447 s]
[INFO] Tajo Core Tests ................................... FAILURE [07:41 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 11:52 min
[INFO] Finished at: 2015-09-02T05:03:19+00:00
[INFO] Final Memory: 118M/482M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test (default-test) on project tajo-core-tests: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.17:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests> && /home/jenkins/tools/java/jdk1.7.0_25-32/jre/bin/java -Xms512m -Xmx1024m -XX:MaxPermSize=152m -Dfile.encoding=UTF-8 -Dderby.storage.pageSize=1024 -Dderby.stream.error.file=/dev/null -jar <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefirebooter4128481277553973539.jar> <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefire2644299504174244528tmp> <https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefire_142321381133804509441tmp>
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/PluginExecutionException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-core-tests
Build step 'Execute shell' marked build as failure
Updating TAJO-1808
Jenkins build is back to normal : Tajo-master-build #823
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Tajo-master-build/823/>