Skip to main content
iamfromsky
iamfromsky
Gold ⭐️
April 25, 2021
Solved

MapReduce failed since Task connection timeout with App master

Recently, MapReduce job sometimes failed, the details as below:

 

1619338128349.jpg

after check map tasks , the log like below:

 

Log Type: syslog

Log Upload Time: Sun Apr 25 13:54:17 +0800 2021

Log Length: 5507

2021-04-25 13:51:01,806 INFO [main] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
2021-04-25 13:51:01,893 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
2021-04-25 13:51:01,893 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system started
2021-04-25 13:51:01,895 INFO [main] org.apache.hadoop.mapred.YarnChild: Executing with tokens:
2021-04-25 13:51:01,895 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: mapreduce.job, Service: job_1618548626214_99981, Ident: (org.apache.hadoop.mapreduce.security.token.JobTokenIdentifier@732c2a62)
2021-04-25 13:51:02,182 INFO [main] org.apache.hadoop.mapred.YarnChild: Sleeping for 0ms before retrying again. Got null now.
2021-04-25 13:51:06,267 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 0 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:10,268 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 1 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:14,268 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 2 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:18,268 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 3 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:22,269 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 4 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:26,270 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 5 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:30,271 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 6 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:34,272 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 7 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:38,272 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 8 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:42,272 INFO [main] org.apache.hadoop.ipc.Client: Retrying connect to server: dataware-3/10.39.58.16:1079. Already tried 9 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)
2021-04-25 13:51:45,274 WARN [main] org.apache.hadoop.mapred.YarnChild: Exception running child : java.net.ConnectException: Call From dataware-14/10.39.58.19 to dataware-3:1079 failed on connection exception: java.net.ConnectException: Connection timed out; For more details see: http://wiki.apache.org/hadoop/ConnectionRefused
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.apache.hadoop.net.NetUtils.wrapWithMessage(NetUtils.java:791)
at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:731)
at org.apache.hadoop.ipc.Client.call(Client.java:1508)
at org.apache.hadoop.ipc.Client.call(Client.java:1441)
at org.apache.hadoop.ipc.WritableRpcEngine$Invoker.invoke(WritableRpcEngine.java:246)
at com.sun.proxy.$Proxy9.getTask(Unknown Source)
at org.apache.hadoop.mapred.YarnChild.main(YarnChild.java:132)
Caused by: java.net.ConnectException: Connection timed out
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:530)
at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:494)
at org.apache.hadoop.ipc.Client$Connection.setupConnection(Client.java:648)
at org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:744)
at org.apache.hadoop.ipc.Client$Connection.access$3000(Client.java:396)
at org.apache.hadoop.ipc.Client.getConnection(Client.java:1557)
at org.apache.hadoop.ipc.Client.call(Client.java:1480)
... 4 more

2021-04-25 13:51:45,275 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Stopping MapTask metrics system...
2021-04-25 13:51:45,275 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system stopped.
2021-04-25 13:51:45,275 INFO [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MapTask metrics system shutdown complete.

from the above log, we can see the task connection timeout with App master, but this error happend randomly, who can give me some advises on this error.

 

thanks.

 

 

 

iamfromsky
iamfromskyAnswer
Gold ⭐️
April 28, 2021

this issue has been solved right now. and the investigation road likes below:

when i got this issue from development team, these peoples told me some tasks will be failed, and asked me how to solve it. 

then i open Yarn web ui to check what's exact errors of this issue, and found the connection time out. this is the first vision i have got.

so i was considering why the port can't connect ? maybe there is a firewall ?  or maybe one machine got some problem, when task assigned to this machine, then this issue happended?

these all are my assumption, and after two days checked, the answer is no. since no firewall, and this issue happended randomly on every machine.

 

just yesterday night, i found if the connection port is near 1000, then the job failed and connection timeout, but if the port is near 30000+, there are no any issue happend.

so i am going to check the sysctl.conf, i found the setting for port range is "net.ipv4.ip_local_port_range = 1024 65000",   

 

at last i set the port range between "32678. 655000", this issue has been solved. 

 

 

 

 

View in thread

8 replies

Shifu
Gold ⭐️⭐️
Shifu
Gold ⭐️⭐️
April 25, 2021

Hello @iamfromsky 

 

Upon checking the shared logs I can see that one of your Nodemanager(dataware-14/10.39.58.19) is trying to connect a Nodemanager dataware-3 on port 1079 and it got failed with Connection timed out. You may need to check Nodemanager log of dataware-14, dataware-3 and active resource manager log around 2021-04-25 13:51:45 to find more insight.

 

The connection timed out could happen because of a couple of reasons and it is listed in https://cwiki.apache.org/confluence/display/HADOOP2/ConnectionRefused. It is highly recommended to cross-check all the steps mentioned in the link.

 

There is a high chance of network issues on these nodes. Please check with Linux admin team as well.

Translate
iamfromsky
iamfromskyAuthor
Gold ⭐️
April 25, 2021

you are right, the connection is between two Nodemanager,  and i assume dataware-3 :1079 is app master, another one is a task.  that's why i said the connection timeout is from task to appmaster.

since this kind error just happend randomly, and 1 time per hour, so it's really hard for me to find out root cause. 

 

Translate
Shifu
Gold ⭐️⭐️
Shifu
Gold ⭐️⭐️
April 27, 2021

Generally a container which ends with 000001(example:container_XXX_XXXXXXXXXXXXX_XXXXXX_XX_000001) is the Application Master.

Just cross-check whether you are checking the same to confirm it is an AM.

Translate
Terms & ConditionsAccessibility statement