Panagiotis Garefalakis created HIVE-25049:
---------------------------------------------
Summary: LlapDaemon preemption should not be triggered for same
Vertex tasks
Key: HIVE-25049
URL: https://issues.apache.org/jira/browse/HIVE-25049
Project: Hive
Issue Type: Sub-task
Reporter: Panagiotis Garefalakis
Assignee: Panagiotis Garefalakis
Due to the asynchronous nature of QueryInfo$FinishableState notification, we
usually end up receiving finishable state updates across tasks/queryfragments
with some time difference.
Imagine vertex Map8 with dependency on Map7.
If Map8 vertex is already running with some tasks still pending, we can end-up
in a situation where on Map7 completion, some of the pending Map8 tasks are
getting the finishable state update BEFORE the already running Map8 tasks,
ending up preempting tasks for no reason!
{code:java}
2021-04-22T15:30:45.124Z source:Map 7 updated, notifying: [Map 8]
2021-04-22T15:30:45.125Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="IPC Server handler 3 on 25000"] vertex: Map 8 Received
finishable state update for attempt_1619105382691_0001_1_05_000014_0, state=true
2021-04-22T15:30:45.125Z query-executor-0
class="impl.QueryInfo$FinishableStateTracker" level="INFO" thread="IPC Server
handler 3 on 25000"] Now notifying: Map 8
2021-04-22T15:30:45.125Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="Wait-Queue-Scheduler-0"] Attempting to execute
TaskWrapper{task=attempt_1619105382691_0001_1_05_000014_0, Vertex=Map 8,
inWaitQueue=true, inPreemptionQueue=false, registeredForNotifications=true,
canFinish=true, canFinish(in
2021-04-22T15:30:45.126Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="Wait-Queue-Scheduler-0"] Task
TaskWrapper{task=attempt_1619105382691_0001_1_05_000014_0, Vertex=Map 8,
inWaitQueue=true, inPreemptionQueue=false, registeredForNotifications=true,
canFinish=true, canFinish(in queue)=true, isGuaranteed=false,
firstAttemptStartTime=1619105437749, dagStartTime=1619105422608,
withinDagPriority=74, vertexParallelism= 232, selfAndUpstreamParallelism= 256,
selfAndUpstreamComplete= 17} managed to preempt task
TaskWrapper{task=attempt_1619105382691_0001_1_05_000006_0, Vertex=Map 8,
inWaitQueue=false, inPreemptionQueue=true, registeredForNotifications=true,
canFinish=true, canFinish(in queue)=false, isGuaranteed=false,
firstAttemptStartTime=1619105437737, dagStartTime=1619105422608,
withinDagPriority=74, vertexParallelism= 232, selfAndUpstreamParallelism= 256,
selfAndUpstreamComplete= 15}
2021-04-22T15:30:45.126Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="Wait-Queue-Scheduler-0"] Invoking kill task for
attempt_1619105382691_0001_1_05_000006_0 due to pre-emption to run
attempt_1619105382691_0001_1_05_000014_0
2021-04-22T15:30:45.126Z query-executor-0
class="impl.QueryInfo$FinishableStateTracker" level="INFO" thread="IPC Server
handler 3 on 25000"] Now notifying: Map 8
2021-04-22T15:30:45.126Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="IPC Server handler 3 on 25000"] vertex: Map 8 Received
finishable state update for attempt_1619105382691_0001_1_05_000011_0, state=true
2021-04-22T15:30:45.127Z query-executor-0 class="impl.TaskRunnerCallable"
level="INFO" thread="Wait-Queue-Scheduler-0"] Kill task requested for
id=attempt_1619105382691_0001_1_05_000006_0, taskRunnerSetup=true
2021-04-22T15:30:45.127Z query-executor-0 class="impl.TaskRunnerCallable"
level="INFO" thread="Wait-Queue-Scheduler-0"] Issuing kill to task
attempt_1619105382691_0001_1_05_000006_0
2021-04-22T15:30:45.127Z query-executor-0
class="impl.QueryInfo$FinishableStateTracker" level="INFO" thread="IPC Server
handler 3 on 25000"] Now notifying: Map 8
2021-04-22T15:30:45.127Z query-executor-0 class="task.TezTaskRunner2"
level="INFO" thread="Wait-Queue-Scheduler-0"] Attempting to abort
attempt_1619105382691_0001_1_05_000006_0 due to an invocation of killTask
2021-04-22T15:30:45.128Z query-executor-0 class="tez.TezProcessor"
level="INFO" thread="Wait-Queue-Scheduler-0"] Received abort
2021-04-22T15:30:45.128Z query-executor-0 class="tez.TezProcessor"
level="INFO" thread="Wait-Queue-Scheduler-0"] Forwarding abort to
RecordProcessor
2021-04-22T15:30:45.128Z query-executor-0
class="runtime.LogicalIOProcessorRuntimeTask" dagId="dag_1619105382691_0001_1"
fragmentId="1619105382691_0001_1_05_000011_0" level="INFO"
queryId="hive_20210422153013_397b96bf-d5a6-493a-9c51-9446f64eeed4"
thread="TezTR-382691_1_1_5_11_0"] Waiting for 1 initializers to finish
2021-04-22T15:30:45.128Z query-executor-0 class="tez.MapRecordProcessor"
level="INFO" thread="Wait-Queue-Scheduler-0"] Forwarding abort to mapOp: {} MAP
2021-04-22T15:30:45.128Z query-executor-0 class="vector.VectorMapOperator"
level="INFO" thread="Wait-Queue-Scheduler-0"] Received abort in operator: MAP
2021-04-22T15:30:45.128Z query-executor-0 class="impl.TaskRunnerCallable"
level="INFO" thread="Wait-Queue-Scheduler-0"] Kill request for task
attempt_1619105382691_0001_1_05_000006_0 completed. Informing AM
2021-04-22T15:30:45.128Z query-executor-0 class="impl.TaskExecutorService"
level="INFO" thread="IPC Server handler 3 on 25000"] vertex: Map 8 Received
finishable state update for attempt_1619105382691_0001_1_05_000006_0, state=true
{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
