See <https://builds.apache.org/job/Tajo-master-build/816/changes>
Changes:
[jhkim] TAJO-1799: Fix incorrect event handler when kill-query failed.
------------------------------------------
[...truncated 491460 lines...]
=> out schema:{(3) ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)}
=> in schema:{(2) default.lineitem.l_orderkey (INT4),
default.lineitem.l_linenumber (INT4)}
=> distinct: true, GROUP_BY(10)(l_linenumber), exprs: (count( distinct
default.lineitem.l_linenumber (INT4))), target
list:{default.lineitem.l_linenumber (INT4), unique_key (INT8)}, out schema:{(2)
default.lineitem.l_linenumber (INT4), unique_key (INT8)}, in schema:{(2)
default.lineitem.l_orderkey (INT4), default.lineitem.l_linenumber (INT4)}
=> distinct: false, GROUP_BY(11)(), exprs:
(max(default.lineitem.l_orderkey (INT4))), target list:{maximum (INT4)}, out
schema:{(1) maximum (INT4)}, in schema:{(2) default.lineitem.l_orderkey (INT4),
default.lineitem.l_linenumber (INT4)}
SCAN(0) on default.lineitem
=> filter: default.lineitem.l_orderkey (INT4) = 1000
=> target list: default.lineitem.l_orderkey (INT4),
default.lineitem.l_linenumber (INT4)
=> out schema: {(2) default.lineitem.l_orderkey (INT4),
default.lineitem.l_linenumber (INT4)}
=> in schema: {(16) default.lineitem.l_orderkey (INT4),
default.lineitem.l_partkey (INT4), default.lineitem.l_suppkey (INT4),
default.lineitem.l_linenumber (INT4), default.lineitem.l_quantity (FLOAT8),
default.lineitem.l_extendedprice (FLOAT8), default.lineitem.l_discount
(FLOAT8), default.lineitem.l_tax (FLOAT8), default.lineitem.l_returnflag
(TEXT), default.lineitem.l_linestatus (TEXT), default.lineitem.l_shipdate
(TEXT), default.lineitem.l_commitdate (TEXT), default.lineitem.l_receiptdate
(TEXT), default.lineitem.l_shipinstruct (TEXT), default.lineitem.l_shipmode
(TEXT), default.lineitem.l_comment (TEXT)}
=======================================================
Block Id: eb_1440388747324_1440_000002 [INTERMEDIATE]
=======================================================
[Incoming]
[q_1440388747324_1440] 1 => 2 (type=HASH_SHUFFLE, key=?distinctseq (INT2),
default.lineitem.l_linenumber (INT4), num=32)
[Outgoing]
[q_1440388747324_1440] 2 => 3 (type=HASH_SHUFFLE, key=, num=1)
[Enforcers]
0: type=Distinct,alg=hash
DISTINCT_GROUP_BY(12)()
=> exprs: (count( distinct default.lineitem.l_linenumber (INT4)),max(maximum
(INT4)))
=> target list: ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)
=> out schema:{(3) ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)}
=> in schema:{(3) ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)}
=> distinct: true, GROUP_BY(13)(l_linenumber), exprs: (count( distinct
default.lineitem.l_linenumber (INT4))), target
list:{default.lineitem.l_linenumber (INT4), unique_key (INT8)}, out schema:{(2)
default.lineitem.l_linenumber (INT4), unique_key (INT8)}, in schema:{(2)
default.lineitem.l_orderkey (INT4), default.lineitem.l_linenumber (INT4)}
=> distinct: false, GROUP_BY(14)(), exprs: (max(maximum (INT4))), target
list:{maximum (INT4)}, out schema:{(1) maximum (INT4)}, in schema:{(2)
default.lineitem.l_orderkey (INT4), default.lineitem.l_linenumber (INT4)}
SCAN(18) on eb_1440388747324_1440_000001
=> out schema: {(3) ?distinctseq (INT2), default.lineitem.l_linenumber
(INT4), maximum (INT4)}
=> in schema: {(3) ?distinctseq (INT2), default.lineitem.l_linenumber
(INT4), maximum (INT4)}
=======================================================
Block Id: eb_1440388747324_1440_000003 [ROOT]
=======================================================
[Incoming]
[q_1440388747324_1440] 2 => 3 (type=HASH_SHUFFLE, key=, num=1)
[Enforcers]
0: type=Distinct,alg=sort,keys=default.lineitem.l_linenumber |
DISTINCT_GROUP_BY(15)()
=> exprs: (count( distinct default.lineitem.l_linenumber (INT4)),max(maximum
(INT4)))
=> target list: ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)
=> out schema:{(2) maximum (INT4), unique_key (INT8)}
=> in schema:{(3) ?distinctseq (INT2), default.lineitem.l_linenumber (INT4),
maximum (INT4)}
=> distinct: true, GROUP_BY(16)(l_linenumber), exprs: (count( distinct
default.lineitem.l_linenumber (INT4))), target
list:{default.lineitem.l_linenumber (INT4), unique_key (INT8)}, out schema:{(2)
default.lineitem.l_linenumber (INT4), unique_key (INT8)}, in schema:{(2)
default.lineitem.l_orderkey (INT4), default.lineitem.l_linenumber (INT4)}
=> distinct: false, GROUP_BY(17)(), exprs: (max(maximum (INT4))), target
list:{maximum (INT4)}, out schema:{(1) maximum (INT4)}, in schema:{(2)
default.lineitem.l_orderkey (INT4), default.lineitem.l_linenumber (INT4)}
SCAN(19) on eb_1440388747324_1440_000002
=> out schema: {(3) ?distinctseq (INT2), default.lineitem.l_linenumber
(INT4), maximum (INT4)}
=> in schema: {(3) ?distinctseq (INT2), default.lineitem.l_linenumber
(INT4), maximum (INT4)}
=======================================================
Block Id: eb_1440388747324_1440_000004 [TERMINAL]
=======================================================
2015-08-24 04:13:29,584 INFO: org.apache.tajo.querymaster.Query (<init>(238)) -
=======================================================
The order of execution:
1: eb_1440388747324_1440_000001
2: eb_1440388747324_1440_000002
3: eb_1440388747324_1440_000003
4: eb_1440388747324_1440_000004
=======================================================
2015-08-24 04:13:29,585 INFO: org.apache.tajo.querymaster.Query (handle(855)) -
Processing q_1440388747324_1440 of type START
2015-08-24 04:13:29,585 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (first(84)) -
Initial executable blocks [eb_1440388747324_1440_000001]
2015-08-24 04:13:29,585 INFO: org.apache.tajo.querymaster.Query (handle(873)) -
q_1440388747324_1440 Query Transitioned from QUERY_NEW to QUERY_RUNNING
2015-08-24 04:13:29,585 INFO: org.apache.tajo.querymaster.Stage
(calculateShuffleOutputNum(999)) - eb_1440388747324_1440_000001, Table's volume
is approximately 1 MB
2015-08-24 04:13:29,585 INFO: org.apache.tajo.querymaster.Stage
(calculateShuffleOutputNum(1003)) - eb_1440388747324_1440_000001, The
determined number of aggregation partitions is 1
2015-08-24 04:13:29,586 INFO: org.apache.tajo.querymaster.Stage
(initTaskScheduler(882)) - org.apache.tajo.querymaster.DefaultTaskScheduler is
chosen for the task scheduling for eb_1440388747324_1440_000001
2015-08-24 04:13:29,588 INFO: org.apache.tajo.storage.FileTablespace
(listStatus(368)) - Total input paths to process : 1
2015-08-24 04:13:29,589 INFO: org.apache.tajo.storage.FileTablespace
(getSplits(572)) - Total # of splits: 1
2015-08-24 04:13:29,589 INFO: org.apache.tajo.querymaster.Stage (run(834)) - 1
objects are scheduled
2015-08-24 04:13:29,589 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(start(130)) - Start TaskScheduler
2015-08-24 04:13:29,590 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(increaseConcurrency(521)) - Assigned host : 127.0.0.1, Unknown Volume : -1,
Concurrency : 1
2015-08-24 04:13:29,591 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(allocateRackTask(762)) - Assigned Local/Rack/Cancel/Total: (0/1/0/1),
Locality: 0.00%, Rack host: asf907.gq1.ygridcore.net
2015-08-24 04:13:29,592 INFO: org.apache.tajo.worker.TaskManager
(createExecutionBlock(112)) - QueryMaster Address:asf907.gq1.ygridcore.net:49908
2015-08-24 04:13:29,603 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(119)) - Tajo Root Dir: hdfs://localhost:41631/tajo
2015-08-24 04:13:29,603 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir>
2015-08-24 04:13:29,606 INFO: org.apache.tajo.worker.TaskManager (handle(182))
- Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000,
Disks:2, vCores:2)
2015-08-24 04:13:29,607 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/1)>
2015-08-24 04:13:29,607 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000001_000000_00 is
changed to TA_PENDING
2015-08-24 04:13:29,607 INFO: org.apache.tajo.worker.TaskImpl (init(195)) -
Initializing: ta_1440388747324_1440_000001_000000_00
2015-08-24 04:13:29,607 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) -
==================================
2015-08-24 04:13:29,608 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) -
* Stage ta_1440388747324_1440_000001_000000_00 is initialized
2015-08-24 04:13:29,608 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) -
* InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 1), Fetches
(total:0) :
2015-08-24 04:13:29,608 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/1/0_0>
2015-08-24 04:13:29,608 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) -
==================================
2015-08-24 04:13:29,608 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000001_000000_00 is
changed to TA_RUNNING
2015-08-24 04:13:29,612 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000001_000000_00 is
changed to TA_SUCCEEDED
2015-08-24 04:13:29,612 INFO: org.apache.tajo.worker.TaskImpl (run(460)) -
ta_1440388747324_1440_000001_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2015-08-24 04:13:29,612 INFO: org.apache.tajo.querymaster.Stage
(transition(1298)) - Stage - eb_1440388747324_1440_000001 finalize HASH_SHUFFLE
(total=1, success=1, killed=0)
2015-08-24 04:13:29,612 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(stop(160)) - Task Scheduler stopped
2015-08-24 04:13:29,613 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(run(122)) - TaskScheduler schedulingThread stopped
2015-08-24 04:13:29,613 INFO: org.apache.tajo.querymaster.Stage
(transition(1309)) - eb_1440388747324_1440_000001, wait for HASH_SHUFFLE
reports. expected Tasks:1
2015-08-24 04:13:29,613 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(135)) - Close
HashShuffleAppender:eb_1440388747324_1440_000001, not a hash shuffle
2015-08-24 04:13:29,614 INFO: org.apache.tajo.querymaster.Stage
(finalizeShuffleReport(1255)) - eb_1440388747324_1440_000001, Finalized
HASH_SHUFFLE reports: 1
2015-08-24 04:13:29,614 INFO: org.apache.tajo.querymaster.Stage
(transition(1356)) - Stage completed - eb_1440388747324_1440_000001 (total=1,
success=1, killed=0)
2015-08-24 04:13:29,614 INFO: org.apache.tajo.worker.TaskManager
(stopExecutionBlock(161)) - Stopped execution block:eb_1440388747324_1440_000001
2015-08-24 04:13:29,614 INFO: org.apache.tajo.querymaster.Query (handle(855)) -
Processing q_1440388747324_1440 of type STAGE_COMPLETED
2015-08-24 04:13:29,614 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next
executable block eb_1440388747324_1440_000002
2015-08-24 04:13:29,614 INFO: org.apache.tajo.querymaster.Query
(executeNextBlock(757)) - Scheduling Stage:eb_1440388747324_1440_000002
2015-08-24 04:13:29,614 INFO: org.apache.tajo.querymaster.Stage
(calculateShuffleOutputNum(999)) - eb_1440388747324_1440_000002, Table's volume
is approximately 0 MB
2015-08-24 04:13:29,615 INFO: org.apache.tajo.querymaster.Stage
(calculateShuffleOutputNum(1003)) - eb_1440388747324_1440_000002, The
determined number of aggregation partitions is 0
2015-08-24 04:13:29,615 INFO: org.apache.tajo.querymaster.Stage
(initTaskScheduler(882)) - org.apache.tajo.querymaster.DefaultTaskScheduler is
chosen for the task scheduling for eb_1440388747324_1440_000002
2015-08-24 04:13:29,615 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1044)) - eb_1440388747324_1440_000002, Table's volume is
approximately 0 MB
2015-08-24 04:13:29,615 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1048)) - eb_1440388747324_1440_000002, The determined number
of non-leaf tasks is 1
2015-08-24 04:13:29,615 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleHashShuffledFetches(865)) - eb_1440388747324_1440_000002,
ScheduleHashShuffledFetches - Max num=1, finalFetchURI=0
2015-08-24 04:13:29,616 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleHashShuffledFetches(885)) - eb_1440388747324_1440_000002,
DeterminedTaskNum : 1
2015-08-24 04:13:29,616 INFO: org.apache.tajo.querymaster.Stage (run(834)) - 1
objects are scheduled
2015-08-24 04:13:29,616 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(start(130)) - Start TaskScheduler
2015-08-24 04:13:29,619 INFO: org.apache.tajo.worker.TaskManager
(createExecutionBlock(112)) - QueryMaster Address:asf907.gq1.ygridcore.net:49908
2015-08-24 04:13:29,622 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(119)) - Tajo Root Dir: hdfs://localhost:41631/tajo
2015-08-24 04:13:29,622 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir>
2015-08-24 04:13:29,624 INFO: org.apache.tajo.worker.TaskManager (handle(182))
- Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000,
Disks:3, vCores:2)
2015-08-24 04:13:29,624 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/2)>
2015-08-24 04:13:29,625 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000002_000000_00 is
changed to TA_PENDING
2015-08-24 04:13:29,625 INFO: org.apache.tajo.worker.TaskImpl (init(195)) -
Initializing: ta_1440388747324_1440_000002_000000_00
2015-08-24 04:13:29,625 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) -
==================================
2015-08-24 04:13:29,625 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) -
* Stage ta_1440388747324_1440_000002_000000_00 is initialized
2015-08-24 04:13:29,625 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) -
* InterQuery: true, Use HASH_SHUFFLE shuffle, Fragments (num: 0), Fetches
(total:0) :
2015-08-24 04:13:29,625 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/2/0_0>
2015-08-24 04:13:29,626 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) -
==================================
2015-08-24 04:13:29,626 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000002_000000_00 is
changed to TA_RUNNING
2015-08-24 04:13:29,626 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) -
[ta_1440388747324_1440_000002_000000_00] Chunks creation time: 0 msec
2015-08-24 04:13:29,626 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000002_000000_00 is
changed to TA_SUCCEEDED
2015-08-24 04:13:29,626 INFO: org.apache.tajo.worker.TaskImpl (run(460)) -
ta_1440388747324_1440_000002_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2015-08-24 04:13:29,627 INFO: org.apache.tajo.querymaster.Stage
(transition(1298)) - Stage - eb_1440388747324_1440_000002 finalize HASH_SHUFFLE
(total=1, success=1, killed=0)
2015-08-24 04:13:29,627 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(stop(160)) - Task Scheduler stopped
2015-08-24 04:13:29,627 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(run(122)) - TaskScheduler schedulingThread stopped
2015-08-24 04:13:29,627 INFO: org.apache.tajo.querymaster.Stage
(transition(1309)) - eb_1440388747324_1440_000002, wait for HASH_SHUFFLE
reports. expected Tasks:1
2015-08-24 04:13:29,627 INFO:
org.apache.tajo.storage.HashShuffleAppenderManager (close(135)) - Close
HashShuffleAppender:eb_1440388747324_1440_000002, not a hash shuffle
2015-08-24 04:13:29,627 INFO: org.apache.tajo.querymaster.Stage
(finalizeShuffleReport(1255)) - eb_1440388747324_1440_000002, Finalized
HASH_SHUFFLE reports: 1
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Stage
(transition(1356)) - Stage completed - eb_1440388747324_1440_000002 (total=1,
success=1, killed=0)
2015-08-24 04:13:29,628 INFO: org.apache.tajo.worker.TaskManager
(stopExecutionBlock(161)) - Stopped execution block:eb_1440388747324_1440_000002
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Query (handle(855)) -
Processing q_1440388747324_1440 of type STAGE_COMPLETED
2015-08-24 04:13:29,628 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next
executable block eb_1440388747324_1440_000003
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Query
(executeNextBlock(757)) - Scheduling Stage:eb_1440388747324_1440_000003
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Stage
(initTaskScheduler(882)) - org.apache.tajo.querymaster.DefaultTaskScheduler is
chosen for the task scheduling for eb_1440388747324_1440_000003
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1044)) - eb_1440388747324_1440_000003, Table's volume is
approximately 0 MB
2015-08-24 04:13:29,628 INFO: org.apache.tajo.querymaster.Stage
(getNonLeafTaskNum(1048)) - eb_1440388747324_1440_000003, The determined number
of non-leaf tasks is 1
2015-08-24 04:13:29,629 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleHashShuffledFetches(865)) - eb_1440388747324_1440_000003,
ScheduleHashShuffledFetches - Max num=1, finalFetchURI=0
2015-08-24 04:13:29,629 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleHashShuffledFetches(869)) - eb_1440388747324_1440_000003, No Grouping
Column - determinedTaskNum is set to 1
2015-08-24 04:13:29,629 INFO: org.apache.tajo.querymaster.Repartitioner
(scheduleHashShuffledFetches(885)) - eb_1440388747324_1440_000003,
DeterminedTaskNum : 1
2015-08-24 04:13:29,629 INFO: org.apache.tajo.querymaster.Stage (run(834)) - 1
objects are scheduled
2015-08-24 04:13:29,629 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(start(130)) - Start TaskScheduler
2015-08-24 04:13:29,631 INFO: org.apache.tajo.worker.TaskManager
(createExecutionBlock(112)) - QueryMaster Address:asf907.gq1.ygridcore.net:49908
2015-08-24 04:13:29,641 INFO: org.apache.tajo.worker.ExecutionBlockContext
(init(119)) - Tajo Root Dir: hdfs://localhost:41631/tajo
2015-08-24 04:13:29,641 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir>
2015-08-24 04:13:29,643 INFO: org.apache.tajo.worker.TaskManager (handle(182))
- Running ExecutionBlocks: 1, running tasks:0, availableResource: (Memory:1000,
Disks:3, vCores:2)
2015-08-24 04:13:29,643 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/3)>
2015-08-24 04:13:29,643 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000003_000000_00 is
changed to TA_PENDING
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (init(195)) -
Initializing: ta_1440388747324_1440_000003_000000_00
2015-08-24 04:13:29,644 INFO: org.apache.tajo.storage.FileTablespace
(getAppenderFilePath(294)) - Output File Path:
hdfs://localhost:41631/tmp/tajo-jenkins/staging/q_1440388747324_1440/RESULT/part-03-000000-000
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (initPlan(145)) -
Output File Path:
hdfs://localhost:41631/tmp/tajo-jenkins/staging/q_1440388747324_1440/RESULT/part-03-000000-000
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (initPlan(150)) -
==================================
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (initPlan(151)) -
* Stage ta_1440388747324_1440_000003_000000_00 is initialized
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (initPlan(152)) -
* InterQuery: false, Fragments (num: 0), Fetches (total:0) :
2015-08-24 04:13:29,644 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/8565db1e-515f-4525-bfd3-52cc2429367d/tajo-localdir/q_1440388747324_1440/output/3/0_0>
2015-08-24 04:13:29,644 INFO: org.apache.tajo.worker.TaskImpl (initPlan(167)) -
==================================
2015-08-24 04:13:29,645 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000003_000000_00 is
changed to TA_RUNNING
2015-08-24 04:13:29,647 INFO:
org.apache.tajo.engine.planner.physical.ExternalSortExec (info(70)) -
[ta_1440388747324_1440_000003_000000_00] Chunks creation time: 0 msec
2015-08-24 04:13:29,651 INFO: BlockStateChange (logAddStoredBlock(2624)) -
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50487 is added to
blk_1073746381_5557{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-75fef230-5f2d-4f74-98cc-cc0e83f92862:NORMAL:127.0.0.1:50487|FINALIZED]]}
size 0
2015-08-24 04:13:29,652 INFO: org.apache.tajo.worker.TaskAttemptContext
(setState(142)) - Query status of ta_1440388747324_1440_000003_000000_00 is
changed to TA_SUCCEEDED
2015-08-24 04:13:29,652 INFO: org.apache.tajo.worker.TaskImpl (run(460)) -
ta_1440388747324_1440_000003_000000_00 completed. Worker's task counter -
total:1, succeeded: 1, killed: 0, failed: 0
2015-08-24 04:13:29,653 INFO: org.apache.tajo.querymaster.Stage
(transition(1298)) - Stage - eb_1440388747324_1440_000003 finalize NONE_SHUFFLE
(total=1, success=1, killed=0)
2015-08-24 04:13:29,653 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(stop(160)) - Task Scheduler stopped
2015-08-24 04:13:29,653 INFO: org.apache.tajo.querymaster.DefaultTaskScheduler
(run(122)) - TaskScheduler schedulingThread stopped
2015-08-24 04:13:29,653 INFO: org.apache.tajo.querymaster.Stage
(transition(1356)) - Stage completed - eb_1440388747324_1440_000003 (total=1,
success=1, killed=0)
2015-08-24 04:13:29,654 INFO: org.apache.tajo.querymaster.Query (handle(855)) -
Processing q_1440388747324_1440 of type STAGE_COMPLETED
2015-08-24 04:13:29,654 INFO: org.apache.tajo.worker.TaskManager
(stopExecutionBlock(161)) - Stopped execution block:eb_1440388747324_1440_000003
2015-08-24 04:13:29,654 INFO:
org.apache.tajo.engine.planner.global.ParallelExecutionQueue (next(95)) - Next
executable block eb_1440388747324_1440_000004
2015-08-24 04:13:29,654 INFO: org.apache.tajo.querymaster.Query
(transition(802)) - Complete Stage[eb_1440388747324_1440_000003], State:
SUCCEEDED, 3/3.
2015-08-24 04:13:29,654 INFO: org.apache.tajo.querymaster.Query (handle(855)) -
Processing q_1440388747324_1440 of type QUERY_COMPLETED
2015-08-24 04:13:29,655 INFO: org.apache.tajo.querymaster.Query
(finalizeQuery(528)) - Can't find partitions for adding.
2015-08-24 04:13:29,655 INFO: org.apache.tajo.querymaster.Query (handle(873)) -
q_1440388747324_1440 Query Transitioned from QUERY_RUNNING to QUERY_SUCCEEDED
2015-08-24 04:13:29,655 INFO: org.apache.tajo.querymaster.QueryMasterTask
(handle(292)) - Query completion notified from q_1440388747324_1440 final
state: QUERY_SUCCEEDED
2015-08-24 04:13:29,656 INFO: org.apache.tajo.master.QueryInProgress
(heartbeat(252)) - Received QueryMaster
heartbeat:q_1440388747324_1440,state=QUERY_SUCCEEDED,progress=1.0,
queryMaster=asf907.gq1.ygridcore.net
2015-08-24 04:13:29,656 INFO: org.apache.tajo.master.QueryManager
(stopQuery(276)) - Stop QueryInProgress:q_1440388747324_1440
2015-08-24 04:13:29,656 INFO: org.apache.tajo.master.QueryInProgress
(stopProgress(117)) - =========================================================
2015-08-24 04:13:29,656 INFO: org.apache.tajo.master.QueryInProgress
(stopProgress(118)) - Stop query:q_1440388747324_1440
2015-08-24 04:13:29,656 INFO: org.apache.tajo.querymaster.QueryMasterTask
(serviceStop(169)) - Stopping QueryMasterTask:q_1440388747324_1440
2015-08-24 04:13:29,656 INFO: org.apache.tajo.querymaster.QueryMasterTask
(cleanupQuery(468)) - Cleanup resources of all workers. Query:
q_1440388747324_1440, workers: 1
2015-08-24 04:13:29,657 INFO: org.apache.tajo.querymaster.QueryMasterTask
(serviceStop(185)) - Stopped QueryMasterTask:q_1440388747324_1440
Killed
Results :
Tests run: 803, Failures: 0, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [ 2.117 s]
[INFO] Tajo Project POM .................................. SUCCESS [ 1.746 s]
[INFO] Tajo Maven Plugins ................................ SUCCESS [ 3.656 s]
[INFO] Tajo Common ....................................... SUCCESS [ 31.891 s]
[INFO] Tajo Algebra ...................................... SUCCESS [ 2.825 s]
[INFO] Tajo Catalog Common ............................... SUCCESS [ 4.910 s]
[INFO] Tajo Plan ......................................... SUCCESS [ 6.418 s]
[INFO] Tajo Rpc Common ................................... SUCCESS [ 1.359 s]
[INFO] Tajo Protocol Buffer Rpc .......................... SUCCESS [ 48.532 s]
[INFO] Tajo Catalog Client ............................... SUCCESS [ 1.390 s]
[INFO] Tajo Catalog Server ............................... SUCCESS [ 11.384 s]
[INFO] Tajo Storage Common ............................... SUCCESS [ 10.535 s]
[INFO] Tajo HDFS Storage ................................. SUCCESS [ 55.446 s]
[INFO] Tajo PullServer ................................... SUCCESS [ 1.269 s]
[INFO] Tajo Client ....................................... SUCCESS [ 2.488 s]
[INFO] Tajo CLI tools .................................... SUCCESS [ 2.200 s]
[INFO] ASM (thirdparty) .................................. SUCCESS [ 2.046 s]
[INFO] Tajo RESTful Container ............................ SUCCESS [ 4.768 s]
[INFO] Tajo Metrics ...................................... SUCCESS [ 1.383 s]
[INFO] Tajo Core ......................................... SUCCESS [ 11.225 s]
[INFO] Tajo RPC .......................................... SUCCESS [ 0.970 s]
[INFO] Tajo Catalog Drivers Hive ......................... SUCCESS [ 12.875 s]
[INFO] Tajo Catalog Drivers .............................. SUCCESS [ 0.082 s]
[INFO] Tajo Catalog ...................................... SUCCESS [ 1.058 s]
[INFO] Tajo Client Example ............................... SUCCESS [ 1.093 s]
[INFO] Tajo HBase Storage ................................ SUCCESS [ 4.966 s]
[INFO] Tajo Cluster Tests ................................ SUCCESS [ 2.717 s]
[INFO] Tajo JDBC Driver .................................. SUCCESS [ 25.879 s]
[INFO] Tajo Storage ...................................... SUCCESS [ 1.144 s]
[INFO] Tajo Distribution ................................. SUCCESS [ 5.455 s]
[INFO] Tajo Core Tests ................................... FAILURE [14:44 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 19:09 min
[INFO] Finished at: 2015-08-24T04:13:29+00:00
[INFO] Final Memory: 78M/535M
[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 -jar
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefirebooter4803816771013114376.jar>
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefire4285415801789585545tmp>
<https://builds.apache.org/job/Tajo-master-build/ws/tajo-core-tests/target/surefire/surefire_148873174368674113803tmp>
[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-1799
