Zoltan Haindrich created HIVE-19169:
---------------------------------------
Summary: llap: Timed out after 90 secs
Key: HIVE-19169
URL: https://issues.apache.org/jira/browse/HIVE-19169
Project: Hive
Issue Type: Bug
Components: llap
Reporter: Zoltan Haindrich
a more or less recent hive/master with tpcds1000; while running only 1 query at
a time on the cluster; sometimes a "timeout" happens - this could be even a
misconfiguration problem...I'm not sure I've set it up correctly.
what I see from: it seems like the attempt have entered the queue and accepted
- after almost 90 seconds there are messages that it will be pre-empted - and
the 90 sec timeout happens.
hive.log; example: attempt_1522319554594_0065_19_05_000119_14 failed
{code}
2018-04-10T13:20:25,178 ERROR [HiveServer2-Background-Pool: Thread-4194]:
SessionState (SessionState.java:printError(1214)) - Vertex failed,
vertexName=Reducer 3, vertexId=vertex_1522319554594_0065_19_05,
diagnostics=[Task failed, taskId=task_1522319554594_0065_19_05_000119,
diagnostics=[TaskAttempt 0 killed, TaskAttempt 1 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_1 Timed out after 90
secs], TaskAttempt 2 killed, TaskAttempt 3 killed, TaskAttempt 4 killed,
TaskAttempt 5 killed, TaskAttempt 6 killed, TaskAttempt 7 killed, TaskAttempt 8
killed, TaskAttempt 9 killed, TaskAttempt 10 killed, TaskAttempt 11 killed,
TaskAttempt 12 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_12 Timed out after 90
secs], TaskAttempt 13 killed, TaskAttempt 14 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_14 Timed out after 90
secs], TaskAttempt 15 failed,
info=[org.apache.hadoop.ipc.RemoteException(java.lang.RuntimeException):
attempt_1522319554594_0065_19_08_000018_6 was not registered and couldn't be
removed
2018-04-10T13:20:25,260 ERROR [HiveServer2-Background-Pool: Thread-4194]:
ql.Driver (SessionState.java:printError(1214)) - FAILED: Execution Error,
return code 2 from org.apache.hadoop.hive.ql.exec.tez.TezTask. Vertex failed,
vertexName=Reducer 3, vertexId=vertex_1522319554594_0065_19_05,
diagnostics=[Task failed, taskId=task_1522319554594_0065_19_05_000119,
diagnostics=[TaskAttempt 0 killed, TaskAttempt 1 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_1 Timed out after 90
secs], TaskAttempt 2 killed, TaskAttempt 3 killed, TaskAttempt 4 killed,
TaskAttempt 5 killed, TaskAttempt 6 killed, TaskAttempt 7 killed, TaskAttempt 8
killed, TaskAttempt 9 killed, TaskAttempt 10 killed, TaskAttempt 11 killed,
TaskAttempt 12 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_12 Timed out after 90
secs], TaskAttempt 13 killed, TaskAttempt 14 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_14 Timed out after 90
secs], TaskAttempt 15 failed,
info=[org.apache.hadoop.ipc.RemoteException(java.lang.RuntimeException):
attempt_1522319554594_0065_19_08_000018_6 was not registered and couldn't be
removed
org.apache.hive.service.cli.HiveSQLException: Error while processing statement:
FAILED: Execution Error, return code 2 from
org.apache.hadoop.hive.ql.exec.tez.TezTask. Vertex failed, vertexName=Reducer
3, vertexId=vertex_1522319554594_0065_19_05, diagnostics=[Task failed,
taskId=task_1522319554594_0065_19_05_000119, diagnostics=[TaskAttempt 0 killed,
TaskAttempt 1 failed, info=[AttemptID:attempt_1522319554594_0065_19_05_000119_1
Timed out after 90 secs], TaskAttempt 2 killed, TaskAttempt 3 killed,
TaskAttempt 4 killed, TaskAttempt 5 killed, TaskAttempt 6 killed, TaskAttempt 7
killed, TaskAttempt 8 killed, TaskAttempt 9 killed, TaskAttempt 10 killed,
TaskAttempt 11 killed, TaskAttempt 12 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_12 Timed out after 90
secs], TaskAttempt 13 killed, TaskAttempt 14 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_14 Timed out after 90
secs], TaskAttempt 15 failed,
info=[org.apache.hadoop.ipc.RemoteException(java.lang.RuntimeException):
attempt_1522319554594_0065_19_08_000018_6 was not registered and couldn't be
removed
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: Vertex failed,
vertexName=Reducer 3, vertexId=vertex_1522319554594_0065_19_05,
diagnostics=[Task failed, taskId=task_1522319554594_0065_19_05_000119,
diagnostics=[TaskAttempt 0 killed, TaskAttempt 1 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_1 Timed out after 90
secs], TaskAttempt 2 killed, TaskAttempt 3 killed, TaskAttempt 4 killed,
TaskAttempt 5 killed, TaskAttempt 6 killed, TaskAttempt 7 killed, TaskAttempt 8
killed, TaskAttempt 9 killed, TaskAttempt 10 killed, TaskAttempt 11 killed,
TaskAttempt 12 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_12 Timed out after 90
secs], TaskAttempt 13 killed, TaskAttempt 14 failed,
info=[AttemptID:attempt_1522319554594_0065_19_05_000119_14 Timed out after 90
secs], TaskAttempt 15 failed,
info=[org.apache.hadoop.ipc.RemoteException(java.lang.RuntimeException):
attempt_1522319554594_0065_19_08_000018_6 was not registered and couldn't be
removed
{code}
from llap0 logs; filtered for attempt_1522319554594_0065_19_05_000119_14 ;
ordered by time:
{code}
java.lang.RuntimeException: attempt_1522319554594_0065_19_05_000119_14 was not
registered and couldn't be removed
2018-04-10T13:18:45,455 INFO [IPC Server handler 3 on 50155 ()]
org.apache.hadoop.hive.llap.daemon.impl.ContainerRunnerImpl: Queueing container
for execution: fragemendId=attempt_1522319554594_0065_19_05_000119_14,
am_details=lemon-8.openstacklocal:35408, taskInfo= fragment 119 attempt 14,
user=hive, queryId=hive_20180410113951_2fc85570-df7a-4cb1-8499-74d11f227e0d,
appIdString=application_1522319554594_0065, appAttemptNum=1,
containerIdString=container_222212222_0065_01_067763, dagName=with ws as
2018-04-10T13:18:45,457 INFO [IPC Server handler 3 on 50155
(1522319554594_0065_19_05_000119_14)] impl.ContainerRunnerImpl: SubmissionState
for attempt_1522319554594_0065_19_05_000119_14 : ACCEPTED
2018-04-10T13:19:13,533 INFO [Wait-Queue-Scheduler-0 ()]
org.apache.hadoop.hive.llap.daemon.impl.TaskExecutorService: Adding
attempt_1522319554594_0065_19_05_000119_14 to pre-emption queue
2018-04-10T13:19:13,533 INFO [Wait-Queue-Scheduler-0 ()]
org.apache.hadoop.hive.llap.daemon.impl.TaskExecutorService: Attempting to
execute TaskWrapper{task=attempt_1522319554594_0065_19_05_000119_14,
inWaitQueue=true, inPreemptionQueue=false, registeredForNotifications=true,
canFinish=true, canFinish(in queue)=true, isGuaranteed=false,
firstAttemptStartTime=1523364757720, dagStartTime=1523363710305,
withinDagPriority=194, vertexParallelism= 297, selfAndUpstreamParallelism=
1286, selfAndUpstreamComplete= 1243}
2018-04-10T13:19:13,534 WARN [ExecutionCompletionThread #0 ()]
org.apache.hadoop.hive.llap.daemon.impl.TaskExecutorService: Received
onSuccess/onFailure for a fragment for which a completing message was not
received: attempt_1522319554594_0065_19_05_000119_14
2018-04-10T13:19:13,536 ERROR [ExecutionCompletionThread #0 ()]
org.apache.hadoop.hive.llap.daemon.impl.TaskExecutorService: Failed
notification received: Stacktrace: java.lang.RuntimeException:
attempt_1522319554594_0065_19_05_000119_14 was not registered and couldn't be
removed
{code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
