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
