You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hive.apache.org by "Zoltan Haindrich (JIRA)" <ji...@apache.org> on 2018/04/11 06:57:00 UTC

[jira] [Created] (HIVE-19169) llap: Timed out after 90 secs

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)