application master 持續org.apache.hadoop.ipc.Client: Retrying connect to server

    某一個nodemanager退出後，導緻 application master中出現大量的如下日志，并且持續很長時間，application master才成功退出。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

<code>2016-06-24 09:32:35,596 INFO [ContainerLauncher </code><code>#3] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 1 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:35,596 INFO [ContainerLauncher </code><code>#9] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 1 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:35,597 INFO [ContainerLauncher </code><code>#7] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 1 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,455 INFO [ContainerLauncher </code><code>#8] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 7 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,539 INFO [ContainerLauncher </code><code>#5] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 4 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,539 INFO [ContainerLauncher </code><code>#1] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 4 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,539 INFO [ContainerLauncher </code><code>#6] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 3 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,539 INFO [ContainerLauncher </code><code>#2] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 3 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,539 INFO [ContainerLauncher </code><code>#0] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 4 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,596 INFO [ContainerLauncher </code><code>#4] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 2 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,597 INFO [ContainerLauncher </code><code>#3] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 2 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 09:32:36,597 INFO [ContainerLauncher </code><code>#9] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206/192.168.1.199:32951. Already tried 2 time(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>.......</code>

<code>2016-06-24 12:57:52,328 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 8 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:57:53,339 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 9 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:04,357 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 0 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:05,367 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 1 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:06,378 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 2 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:07,392 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 3 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:08,399 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 4 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:09,408 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 5 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:10,417 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 6 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:11,425 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 7 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

<code>2016-06-24 12:58:12,434 INFO [Thread-1835] org.apache.hadoop.ipc.Client: Retrying connect to server: dchadoop206</code><code>/192</code><code>.168.1.199:32951. Already tried 8 </code><code>time</code><code>(s); retry policy is RetryUpToMaximumCountWithFixedSleep(maxRetries=10, sleepTime=1000 MILLISECONDS)</code>

1）dchadoop206上的nodemanager退出後（由于重新開機），導緻application master持續的去連接配接之前nodemanager上的container。顯然這些container是已經連接配接不上了。

2）最終經過非常長的時間大概3-4小時後，連接配接不上的異常才抛出，application master正常結束。

<code>&lt;strong style=</code><code>"font-family:'Source Sans Pro', 'Helvetica Neue', Helvetica, Arial, sans-serif;white-space:normal;color:rgb(51,51,51);font-size:1.4em;line-height:1.1;"</code><code>&gt;&lt;span style=</code><code>"font-family:'黑體', SimHei;font-size:16px;"</code><code>&gt;二、問題分析&lt;</code><code>/span</code><code>&gt;&lt;</code><code>/strong</code><code>&gt;&lt;br&gt;</code>

這個問題主要涉及hadoop的rpc機制。首先看下面兩個配置參數

<code> </code><code>#定義client連接配接到nodemanager的最大逾時時間,不是單次連接配接，而是經過多少時間連接配接不上nodemanager，則認為操作失敗</code>

<code> </code><code>&lt;property&gt;</code>

<code>        </code><code>&lt;name&gt;yarn.client.nodemanager-connect.max-wait-ms&lt;</code><code>/name</code><code>&gt;</code>

<code>        </code><code>&lt;value&gt;15*60*1000&lt;</code><code>/value</code><code>&gt;</code>

<code> </code><code>&lt;</code><code>/property</code><code>&gt;</code>

<code> </code><code># 定義每次嘗試去連接配接nodemanager的時間間隔</code>

<code>        </code><code>&lt;name&gt;yarn.client.nodemanager-connect.retry-interval-ms&lt;</code><code>/name</code><code>&gt;</code>

<code>        </code><code>&lt;value&gt;10*1000&lt;</code><code>/value</code><code>&gt;</code>

    根據這兩個參數的定義，ApplicationMaster經過15分鐘仍然連不上nodemanager的container，會取消try connect。但觀察的情況是Application Master 需要等大約30分鐘，才取消try connect。主要原因在于hadoop 的rpc機制如下，首先ApplicationMaster 會根據上面的兩個參數，構造一個RetryUpToMaximumCountWithFixedSleep的重連政策，這個重連政策會通過以下方式計算

MaximumCount：yarn.client.nodemanager-connect.max-wait-ms/yarn.client.nodemanager-connect.retry-interval-ms=90次

而每次的RPC請求中，Client也有自己的重連政策，就是類似這樣的東東:

<code>由兩個rpc參數控制，ipc.client.connect.max.retries=10和ipc.client.connect.retry.interval=1000ms控制</code>

是以最終ApplicationMaster 放棄try connect的等待時間是：90*(10+10)=1800s

1）在送出map-reduce/hive sql/hive server2等用戶端機器修改yarn-site.xml的以下參數

2）hadoop指令行中通過-D設定該參數

<code>        </code><code>&lt;value&gt;180000&lt;</code><code>/value</code><code>&gt;</code>

這樣總的等待時間就是6分鐘。

這個修改是不需要做任何重新開機yarn元件操作的，是一個用戶端相關的操作！

本文轉自 zouqingyun 51CTO部落格，原文連結：http://blog.51cto.com/zouqingyun/1881294，如需轉載請自行聯系原作者