Hadoop,  Hive,  Tez,  YARN

Hive on Tez – Shuffle Failed with Too Many Fetch Failures and Insufficient Progress

On one of the clusters I noticed an increased rate of shuffle errors, and the restart of a job did not help, it still failed with the same error.

The error was as follows:

 Error: Error while running task ( failure ) : 
    error in shuffle in Fetcher 
 at org.apache.tez.runtime.library.common.shuffle.orderedgrouped.Shuffle$RunShuffleCallable.callInternal

Caused by: java.io.IOException: 
  Shuffle failed with too many fetch failures and insufficient progress!failureCounts=1,
    pendingInputs=1, fetcherHealthy=false, reducerProgressedEnough=true, reducerStalled=true

Looking at the container log I could see more details:

2020-02-26 13:09:38,159 [WARN] [Fetcher #0] |orderedgrouped.FetcherOrderedGrouped|: 
  Failed to verify reply after connecting to with 1 inputs pending

  java.io.IOException: Server returned HTTP response code: 401 for URL:
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1876)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
	at org.apache.tez.http.HttpConnection.getInputStream(HttpConnection.java:248)
  at org.apache.tez.runtime.library.common.shuffle.orderedgrouped.FetcherOrderedGrouped
   .setupConnection (FetcherOrderedGrouped.java:348)
  at org.apache.tez.runtime.library.common.shuffle.orderedgrouped.FetcherOrderedGrouped
   .copyFromHost (FetcherOrderedGrouped.java:260)
  at org.apache.tez.runtime.library.common.shuffle.orderedgrouped.FetcherOrderedGrouped
   .fetchNext (FetcherOrderedGrouped.java:178)

Notice HTTP response code: 401 returned by a remote Node Manager when requesting a map output. How is it possible that the Node Manager return HTTP 401 (Unauthorized) error ?

One of the possible reasons is the Node Manager restart during the job execution. To check this I went to the host and checked its Node Manager log:

$ ssh -i key hadoop@

$cat /var/log/hadoop-yarn/yarn-yarn-nodemanager-ip-10-85-65-44.log

In the log I can see that the Node Manager is started during the job execution. That means it was terminated before that:

2020-02-26 13:09:23,233 INFO org.apache.hadoop.yarn.webapp.WebApps (main): Web app node started at 8042
2020-02-26 13:09:23,239 INFO org.apache.hadoop.yarn.client.RMProxy (main): Connecting to 
 ResourceManager at
2020-02-26 13:09:23,259 INFO org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl (main): 
 Sending out 0 NM container statuses: []
2020-02-26 13:09:23,264 INFO org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl (main): 
 Registering with RM using containers :[]
2020-02-26 13:09:23,306 INFO org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl (main): 
  Registered with ResourceManager as with total resource of <memory:53248, vCores:36>

And later in the same log:

2020-02-26 13:09:25,953 WARN org.apache.hadoop.mapred.ShuffleHandler (New I/O worker #2): 
  Shuffle failure org.apache.hadoop.security.token.SecretManager$InvalidToken: 
    Can't find job token for job job_1581241769187_51527 !!

job_1581241769187_51527 is exactly the same job that failed with HTTP 401 error when asking for a map output for from this node!

So the reason of the error is the Node Manager restart (probably due to Java Heap Space or other error) that lost the security token and cannot allow other Node Managers to get the shuffle data.

If it is not a transient error it makes sense to investigate why the Node Manager terminates and then restarts (in my case by the Amazon EMR instance controller) and try to resolve it.