本文導讀：
- 生產故障場景介紹
- TCP 建連三次握手過程
- TCP 斷連四次揮手過程
- 結合 Java 堆棧剖析源碼
- 再從堆棧中找到"罪魁禍首"
- 問題優化方案總結
1、生產故障場景介紹
業務簡介：
該服務主要是提供對外的代理接口，大部分接口都會調用第三方接口，獲取數據后做聚合處理后，提供給客戶端使用。
有一天晚上，系統正處於高峰期間，項目組小伙伴正在津津有味的吃着「加班餐」，剛把🍚塞進嘴里，郵件和短信同時發起來告警。
有一台服務器接口超時，平時偶爾也會收到類似告警，有時會因為網絡波動等原因。實在不好意思，沒事總讓人家「網絡」同學背鍋 : )。但是，這次告警並沒有收斂，持續告警了十幾分鍾以上，感到了不妙。
點擊郵件中告警的 URL 接口鏈接，一直在頁面轉圈圈，響應很慢，悲劇！
此刻，默默的把🍱盒飯推到一邊去，不忍直視 😦
問題定位基本流程：
1）確定影響范圍
該服務后面掛着多台服務器，僅有一台服務器掛掉了，所以對用戶不會有太大的影響。
先臨時從注冊中心上摘掉，別讓客戶端繼續重試到這台機器上了，保留事故現場。
2）排查監控指標
查看接口服務的訪問量，因為是晚高峰，因此會比其他時間段用戶訪問量會更大些，但是這個訪問量看上去跟平時同一時段對比，並沒有特別明顯突增現象。
監控上觀察服務器的 CPU、內存、IO、網絡指標看起來也一切正常。
3）服務器排查
登錄到服務器上，結合監控進一步查看服務器 CPU、內存 等指標，查看服務日志都是正常的，並且也沒有發現特別的異常日志輸出，Exception 或者 OOM 等異常。
我們看到的現象是，接口服務已經無法正常響應了，應用跑在 JVM 上，快速通過 JDK 自帶的常用命令排查一番了。
如下命令打印堆棧信息：
jstack -l $pid > jstack.log
統計結果如下：
cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c
994 java.lang.Thread.State: WAITING (parking)
501 java.lang.Thread.State: WAITING (on object monitor)
7 java.lang.Thread.State: TIMED_WAITING (sleeping)
13 java.lang.Thread.State: TIMED_WAITING (parking)
2 java.lang.Thread.State: TIMED_WAITING (on object monitor)
23 java.lang.Thread.State: RUNNABLE
如果遇到 java.lang.Thread.State: WAITING (parking)、java.lang.Thread.State: WAITING (on object monitor) 這類線程狀態，就要引起注意了，一般可能都是程序本身問題導致的。
根據 java.lang.Thread.State: WAITING 查看 jstack.log 里的堆棧信息，發現了了大量的調用 HttpClient 工具類請求等待掛起的日志，具體堆棧信息待下面詳細分析。
這些服務調用都是通過 HttpClient 工具直接調用的，對 Spring RestTemplate 做了一次封裝，其底層也是調用的 Apache HttpClient 工具類來實現服務調用的。
除看到上述 jstack 日志異常外，還排查了服務器上的網絡狀態，這也是運維同學們常用的排查手段。
附上統計網絡連接狀態的命令：
netstat -n | awk '/^tcp/ {++State[$NF]} END {for(i in State) print i, State[i]}'
統計結果：
TIME_WAIT 9
CLOSE_WAIT 3826
SYN_SENT 2
ESTABLISHED 28
SYN_RECV 8
這里注意了，我們看到服務器詭異的網絡連接統計中，出現了大量的 CLOSE_WAIT 狀態的連接。
而且這個狀態，當你間隔一段時間再次執行統計命令，還是會存在，也就是不會被釋放掉了，看上去問題有些嚴重。
進一步猜測，出現這些 CLOSE_WAIT 狀態跟接口響應慢應該是有關系的，同時，也跟 java 堆棧信息中出現的 HttpClient 線程阻塞有關系，作為問題突破口去分析。
不如，我們先來了解下 CLOSE_WAIT 狀態，這個 CLOSE_WAIT 狀態處於 TCP 網絡斷開連接過程中，當客戶端發起斷連請求，服務端首次收到斷連請求，回復確認消息，之后便處於 CLOSE_WAIT 狀態了，當服務端響應處理完畢會回復網絡包給客戶端，正常連接會被關閉掉的。
2、 TCP 建連三次握手過程
盡管 CLOSE_WAIT 狀態是在 TCP 網絡連接四次揮手過程中的。我們還是有必要，先來了解下 TCP 網絡連接的三次握手，因為它是請求服務器要做的第一件事情，那就是建立 TCP 連接。
技術源於生活。
我們可以舉個日常生活中的例子來理解 TCP 三次握手的過程。
比如你在微信上想與一位很久未曾謀面的朋友聊一聊：
小東：小升，在嗎？
（過了很久... ... ）
小升: 在了，你還在嗎？
（小東剛好在線，天天刷朋友圈... ... ）
小東：嗯嗯，在了
（然后兩位開始熱聊起來... ...）
如果你平時跟朋友，開頭總這么聊天是不是覺得很累呢。
其實上面的過程，可以很好的理解 TCP 三次握手的過程。
我們姑且將小東看做是「客戶端」，小升看做是「服務端」。
小東是做名程序員，做 IT 工作。小升在老家開店創業中。
理解TCP三次握手過程：
1）小東作為「客戶端」，向作為「服務端」的小升發起聊天，就是發送了一個網絡包（包簽名為 syn ）給小升。【這是 TCP 第一次握手，小東狀態此時處於 syn_sent 狀態】
2）小升收到了小東的聊天網絡包，你得確認下吧，表示你收到了。此時，小升還有別的事情，不像小東那樣搞 IT 工作的，上班還上着微信。到了晚上，小升得空看了一眼手機微信，彈出了小東的消息。然后，激動的做了個回復「 針對小東發來的 sync 包，做了個 ack 回復確認」。因隔了一段時間了，小升也不確定小東還在不在線了。【這是 TCP 第二次握手，小升狀態此時處於 syn_rcvd 狀態 】
3）小東因為剛好在線，收到了小升的回復確認消息，馬上對這次消息做了一個回復「對着小升給的 sync + ack，做了進一步 ack 回復確認，這是 TCP 第三次握手」 。【小升狀態此時變成了 established 可馬上聊天狀態】
4）此時，小升也在線，兩位就開始熱聊起來了。【正式傳輸數據了，小東和小升的狀態都處於 established 狀態】
上述提到的那些狀態 syn_sent syn_rcvd established ，正是 TCP 三次握手過程中涉及的關鍵狀態。
上一張圖來直觀理解下：
3、 TCP 斷連四次揮手過程
小東和小升的熱聊結束了，已經很晚了，也忙了一天了，需要休息了。
小東因工作原因明天要早起，所以提前跟小升說了：
小東：明天要凌晨4點起床升級系統，我要早點休息了，改天過來請你喝酒！
小升：額 ？？？這樣，反正我也不懂！
小升：那你早點休息吧。你說的這頓酒還是要喝的！
小東：嗯嗯，晚安啊！你也早點休息。
小升：好的，晚安，兄弟！
對應理解 TCP 四次揮手過程：
1）小東要休息了，發起了 fin1 包打算結束聊天了。【小東狀態此時處於 fin_wait1 狀態，這是 TCP 第一次揮手】
2）小升收到了小東的 fin1 包，回復了 ack 確認消息。【此時，小升狀態處於 close_wait 狀態，小東此時狀態為 fin_wait2，這是 TCP 第二次揮手】
3）小升來了一次最后確認，不打算繼續聊了，發送了 fin2 包。【此時，小升狀態處於 last_ack 狀態，這是 TCP 第三次揮手】
4）小東針對小升發來的 fin2 包，最終回復了個 ack 確認。【此時，小東狀態處於 time_wait 狀態，這是 TCP 第四次揮手】
為什么小東還要處於 time_wait 狀態等一下呢？
因為他們按照「老規矩」，得確保最后這次消息小升的確收到了，才能最終結束這次聊天。
time_wait 狀態標准持續等待時間是** 4** 分鍾，在這段時間內，小東和小升建立的 TCP 網絡連接套接字資源（端口），是不能被其他人所使用的，也不能被系統回收重新利用的。
如果小升沒有收到反饋，還會繼續問下「重發 fin2 消息」，直到小東發送了 ack 消息成功了。
雙方正式關閉聊天通道，釋放端口資源，連接關閉。
等待的 4 分鍾就是 2 個 MSL，每個 MSL 是 2 分鍾。MSL就是 maximium segment lifetime——最長報文壽命。這個時間是由官方 RFC 協議規定的。
上一張圖，進一步直觀理解下：
4、結合 Java 堆棧剖析源碼
分析完 TCP 四次揮手過程了，當服務端接收到 TCP 斷開連接的請求包，需要回復一個確認消息給客戶端，此時服務端狀態便處於 CLOSE_WAIT 狀態了。
我們清楚了該狀態所在的網絡連接中的位置，結合前文中提到的問題，大量的線程阻塞在了 HttpClient 調用上。線程狀態為 WAITING，服務器上統計出來，有大量處於 CLOSE_WAIT 狀態的網絡連接無法釋放。
線程是 JVM 進程中比較寶貴的資源，如果一直有大量線程處於等待或阻塞狀態，慢慢的所有線程都被占滿，導致服務沒法正常響應了。
我們來通過 java 線程堆棧信息，再結合源碼來分析下具體原因。
找到第一段關鍵的堆棧日志：
"http-nio-8970-exec-1108" #24971 daemon prio=5 os_prio=0 tid=0x00007f45b4445800 nid=0x61ad waiting on condition [0x00007f444ad69000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c2f30968> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:380)
at org.apache.http.pool.AbstractConnPool.access$200(AbstractConnPool.java:69)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:246)
- locked <0x0000000641c7fe38> (a org.apache.http.pool.AbstractConnPool$2)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:193)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:303)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:279)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:191)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:89)
at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:660)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:629)
at org.springframework.web.client.RestTemplate.getForEntity(RestTemplate.java:329)
at com.xxx.proxy.common.util.HttpClientUtil.getForEntity(HttpClientUtil.java:267)
at com.xxx.proxy.common.util.HttpClientUtil.getForObject(HttpClientUtil.java:521)
... ...
堆棧日志中出現了大量的上述日志，基本都是 HttpClient 工具類所調用的，所有線程狀態處於 java.lang.Thread.State: WAITING (parking) 狀態。
出現 WAITING (parking)線程掛起狀態，因為接口服務內部大量調用了第三方接口，要獲取 Http 連接，但始終無法獲取到，只能等待。
HttpClientUtil 工具類是繼承自 Spring RestTemplate 並做了一些參數、重試機制、代理定制，其包路徑位於 org.springframework.web.client.RestTemplate 。
類圖如下所示：
創建 HttpClient 工具示例代碼：
HttpClientFactoryBean httpClientFactoryBean = new HttpClientFactoryBean(config);
HttpComponentsClientHttpRequestFactory httpRequestFactory = new HttpComponentsClientHttpRequestFactory(httpClientFactoryBean.getObject());
return new HttpClientUtil(httpRequestFactory);
HttpClientFactoryBean 繼承自 AbstractFactoryBean，重寫 getObjectType() 和 createInstance() 方法。
類圖如下所示：
HttpClientFactoryBean 部分示例方法：
@Override
public Class<?> getObjectType() {
return HttpClient.class;
}
@Override
protected HttpClient createInstance() {
if (restConfig == null) {
HttpClients.custom().build();
}
// 每個路由最大的連接數
int maxPerRoute = restConfig.getMaxConnections();
// 總的最大連接數
int maxTotal = restConfig.getMaxTotalConnections();
// 連接超時時間
int connectTimeout = restConfig.getConnectionTimeout();
// 讀取數據的超時時間
int socketTimeout = restConfig.getTimeout();
PoolingHttpClientConnectionManager connManager = new PoolingHttpClientConnectionManager(30, TimeUnit.SECONDS);
connManager.setDefaultMaxPerRoute(maxPerRoute);
connManager.setMaxTotal(maxTotal);
connManager.setValidateAfterInactivity(1000);
RequestConfig requestConfig = RequestConfig.custom().setConnectTimeout(connectTimeout) .setSocketTimeout(socketTimeout).build();
/ ... 省略部分代碼
return HttpClients.custom().setConnectionManager(connManager).evictExpiredConnections().setDefaultRequestConfig(requestConfig).build();
}
根據堆棧信息也能看到是從 PoolingHttpClientConnectionManager 的 leaseConnection() 方法獲取連接，那我們可以詳細看下源代碼，為什么沒有獲取成功呢？
怎么查找源碼，通過堆棧信息中的調用棧鏈路，就能非常容易的找到經過了哪些類哪些方法，第多少行代碼。
根據上面jstack中的日志：
org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:380)
根據名稱猜測，通過 AbstractConnPool 抽象連接池的類，調用 getPoolEntryBlocking 阻塞式方法獲取連接，第 380 行代碼。
查看源碼：
private E getPoolEntryBlocking(
final T route, final Object state,
final long timeout, final TimeUnit tunit,
final Future<E> future) throws IOException, InterruptedException, TimeoutException {
Date deadline = null;
// 連接獲取超時時間參數
if (timeout > 0) {
deadline = new Date (System.currentTimeMillis() + tunit.toMillis(timeout));
}
this.lock.lock();
try {
final RouteSpecificPool<T, C, E> pool = getPool(route);
// .... 省略部分源碼
boolean success = false;
try {
if (future.isCancelled()) {
throw new InterruptedException("Operation interrupted");
}
// 將 future，實際類型為 Future<CPoolEntry>，放入 pending 雙向鏈表隊列中
pool.queue(future);
this.pending.add(future);
if (deadline != null) {
success = this.condition.awaitUntil(deadline);
} else {
// 這里正是第 380 行源代碼
this.condition.await();
success = true;
}
if (future.isCancelled()) {
throw new InterruptedException("Operation interrupted");
}
} finally {
// In case of 'success', we were woken up by the
// connection pool and should now have a connection
// waiting for us, or else we're shutting down.
// Just continue in the loop, both cases are checked.
pool.unqueue(future);
this.pending.remove(future);
}
// check for spurious wakeup vs. timeout
if (!success && (deadline != null && deadline.getTime() <= System.currentTimeMillis())) {
break;
}
}
throw new TimeoutException("Timeout waiting for connection");
} finally {
this.lock.unlock();
}
}
查找到第 380 行源碼，調用了 condition 的 await() 方法：
this.condition.await();
這里使用了並發包下的 Condition 實現多線程協調通訊機制，await() 方法調用后，會將當前線程加入到 Condition 等待隊列中，是一個FIFO結構的隊列，同時當前線程鎖釋放，如果不釋放，會導致其他線程無法獲得鎖，可能造成死鎖。
await() 方法源碼：
public final void await() throws InterruptedException {
if (Thread.interrupted())
throw new InterruptedException();
// 加入 Condition 等待隊列
Node node = addConditionWaiter();
// 釋放當前線程的鎖
long savedState = fullyRelease(node);
int interruptMode = 0;
// 不在 AQS 同步隊列中，將當前線程掛起，如果在 AQS 隊列中退出循環
while (!isOnSyncQueue(node)) {
LockSupport.park(this);
if ((interruptMode = checkInterruptWhileWaiting(node)) != 0)
break;
}
// 已被 signal() 方法喚醒，自旋等待嘗試再次獲取鎖
if (acquireQueued(node, savedState) && interruptMode != THROW_IE)
interruptMode = REINTERRUPT;
if (node.nextWaiter != null) // clean up if cancelled
unlinkCancelledWaiters();
if (interruptMode != 0)
reportInterruptAfterWait(interruptMode);
}
當前線程加入 Condition 等待隊列結構圖：
當通過 Condtion 調用 signalAll() 或者 signal() 方法時，會獲取等待隊列的首節點，將其移動到同步隊列，利用 LockSupport 喚醒節點中的線程。節點從等待隊列，移動到 AQS 同步隊列如下結構圖所示：
在 AbstractConnPool 類的找到了 release() 釋放連接的代碼。
release() 方法源碼如下：
@Override
public void release(final E entry, final boolean reusable) {
this.lock.lock();
try {
if (this.leased.remove(entry)) {
final RouteSpecificPool<T, C, E> pool = getPool(entry.getRoute());
pool.free(entry, reusable);
if (reusable && !this.isShutDown) {
this.available.addFirst(entry);
} else {
entry.close();
}
onRelease(entry);
Future<E> future = pool.nextPending();
if (future != null) {
this.pending.remove(future);
} else {
future = this.pending.poll();
}
if (future != null) {
this.condition.signalAll();
}
}
} finally {
this.lock.unlock();
}
}
我們看到了釋放連接時，調用 this.condition.signalAll(); signalAll() 方法的調用會喚醒所有的所有等待隊列線程，雖然喚醒所有，但是仍然只有一個線程能拿到鎖，其他線程還是需要自旋等待。
signalAll() 方法源碼如下：
private void doSignalAll(Node first) {
lastWaiter = firstWaiter = null;
do {
Node next = first.nextWaiter;
first.nextWaiter = null;
// 信號通知
transferForSignal(first);
first = next;
} while (first != null);
}
final boolean transferForSignal(Node node) {
/*
* 設置node的waitStatus：Condition->0
*/
if (!compareAndSetWaitStatus(node, Node.CONDITION, 0))
return false;
// 加入到AQS的等待隊列，讓節點繼續獲取鎖，設置前置節點狀態為SIGNAL
Node p = enq(node);
int c = p.waitStatus;
if (c > 0 || !compareAndSetWaitStatus(p, c, Node.SIGNAL))
// 調用 LockSupport 的 unpark() 方法喚醒線程
LockSupport.unpark(node.thread);
return true;
}
剖析完了底層代碼，回過頭去，我們看下是因為調用到了 condition 的 await() 無參方法，並且一直無法獲得 Http 連接，然后一直占着 tomcat 線程的坑。
getPoolEntryBlocking() 方法的最開始，有個不能忽視的一段代碼：
Date deadline = null;
// 連接獲取超時時間參數
if (timeout > 0) {
deadline = new Date (System.currentTimeMillis() + tunit.toMillis(timeout));
}
這段代碼一看就是超時時間，猜測一下，代碼在此處，timeout 應該就是從連接池獲取連接時的等待時間。
getPoolEntryBocking() 方法的下面看到：
if (deadline != null) {
success = this.condition.awaitUntil(deadline);
}
如果 deadline 不為空，會調用 condtion 的 awaitUtil(deadline) 方法，awaitUtil(deadline) 發方法表示直到達到 deadline 時間還未喚醒，就會自動喚醒，加入 AQS 同步隊列獲取鎖。
我們可以根據堆棧信息繼續往前查找調用者，看看 deadline 中的 timeout 來源。
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:191)
MainClientExec#execute() 方法部分源碼：
final HttpClientConnection managedConn;
try {
final int timeout = config.getConnectionRequestTimeout();
managedConn = connRequest.get(timeout > 0 ? timeout : 0, TimeUnit.MILLISECONDS);
} catch(final InterruptedException interrupted) {
}
這里的 timeout，即 connectionRequestTimeout，正是計算 deadline 時間的 timeout 值。
印證了我們的猜測。
初始化 HttpClient 工具的初始配置參數，並沒有配置 connectionRequestTimeout 這個參數的，該參數也是很關鍵的，如果沒有設置，並且被 park 掛起的線程一直沒有被 signal 喚醒，那么會一直等待下去。
所以，必須得設置這個參數。這里的 deadline 是個絕對時間，不為空時，會調用 condition 的 awaitUtil(deadline) 方法，即使沒有被 signal 喚醒，也會自動喚醒，去爭搶鎖，而不會導致未被喚醒就一直阻塞下去。
而且這個 awaitUtil(deadline) 方法跟 awaitNanos(long nanosTimeout) 方法里的 deadline 變量設計上異曲同工。
達到了設定的超時時間，並且沒有 signal 過，最終 success 變量為 false 不成功，直接 break 跳出循環，最終會拋出 TimeoutException("Timeout waiting for connection") 異常。
拋出這個異常，系統錯誤日志中，也就明確了是因為無法獲得連接導致的。同時，也避免了一直占用着線程。
5、再從堆棧中找到"罪魁禍首"
上一節，從第一段堆棧日志分析到了 Condition 並發底層源碼細節。
但是這還沒完，因為我們統計 java.lang.Thread.State 中，僅分析完了WAITING (parking) 狀態，問題原因也不一定是這個狀態導致的。接下來繼續分析另外的「異常」線程狀態 WAITING (on object monitor) 。
在 java 堆棧中 第二段關鍵的日志 如下：
"http-nio-8970-exec-462" #24297 daemon prio=5 os_prio=0 tid=0x00007f45b41bd000 nid=0x5f0b in Object.wait() [0x00007f446befa000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.net.InetAddress.checkLookupTable(InetAddress.java:1393)
- locked <0x00000006c05a5570> (a java.util.HashMap)
at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1310)
at java.net.InetAddress.getAllByName0(InetAddress.java:1276)
at java.net.InetAddress.getAllByName(InetAddress.java:1192)
at java.net.InetAddress.getAllByName(InetAddress.java:1126)
at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:45)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:112)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:89)
at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:660)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:629)
at org.springframework.web.client.RestTemplate.getForEntity(RestTemplate.java:329)
at com.xxx.tvproxy.common.util.HttpClientUtil.getForEntity(HttpClientUtil.java:267)
at com.xxx.tvproxy.common.util.HttpClientUtil.getForObject(HttpClientUtil.java:521)
``
java.lang.Thread.State: WAITING (on object monitor)，這樣的線程狀態也要引起格外的注意，監視對象鎖，並且一直阻塞着線程不釋放。
根據線程堆棧信息看，猜測就是跟 HttpClient 參數設置有關，我們來分析下創建參數。
查找棧頂信息看到了有調用 Object 對象的 wait() 方法，說明是在等待另外的線程 notify 通知，但遲遲未等到，當前線程就一直處於 WAITING 狀態。
繼續查找是誰調用的：
at java.net.InetAddress.checkLookupTable(InetAddress.java:1393)
``
這段代碼調用引起，還是要去看下源碼：
private static InetAddress[] checkLookupTable(String host) {
synchronized (lookupTable) {
// If the host isn't in the lookupTable, add it in the
// lookuptable and return null. The caller should do
// the lookup.
if (lookupTable.containsKey(host) == false) {
lookupTable.put(host, null);
return null;
}
// If the host is in the lookupTable, it means that another
// thread is trying to look up the addresses of this host.
// This thread should wait.
while (lookupTable.containsKey(host)) {
try {
// 對應堆棧中的 java.net.InetAddress.checkLookupTable(InetAddress.java:1393)
lookupTable.wait();
} catch (InterruptedException e) {
}
}
}
// The other thread has finished looking up the addresses of
// the host. This thread should retry to get the addresses
// from the addressCache. If it doesn't get the addresses from
// the cache, it will try to look up the addresses itself.
InetAddress[] addresses = getCachedAddresses(host);
if (addresses == null) {
synchronized (lookupTable) {
lookupTable.put(host, null);
return null;
}
}
return addresses;
}
找到了是 lookupTable 對象，使用了同步塊鎖 synchronized，內部調用了 lookupTable 對象的 wait() 方法，就是在這里等不到通知，一直阻塞着。
這個問題代碼排查一通，你是看不出什么問題來的，因為跟應用程序本身關系不大了，是因為 IPV6 導致的 JVM 線程死鎖問題。
參考國外 zimbra 站點 wiki：https://wiki.zimbra.com/wiki/Configuring_for_IPv4
這里解釋下問題產生的原因：
應用本身在 IPv4 環境下，如果嘗試使用了 IPv6 會導致一些已知問題。
當調用了 Inet6AddressImpl.lookupAllHostAddr() 方法，因為 Java 與操作系統 libc 庫之間存在一個bug，當特定的競態條件發生時，將會導致查找 host 地址動作一直無限循環下去。這種情況發生的頻率很低，但是一旦發生將會導致 JVM 死鎖問題，進而導致 JVM 中所有線程會被阻塞住。
根據上述分析，在 jstack 堆棧中找到了 第三段關鍵的堆棧日志 如下：
java.lang.Thread.State: RUNNABLE
at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928)
at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323)
at java.net.InetAddress.getAllByName0(InetAddress.java:1276)
at java.net.InetAddress.getAllByName(InetAddress.java:1192)
at java.net.InetAddress.getAllByName(InetAddress.java:1126)
at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:45)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:112)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at
... ...
如何判斷操作系統是否啟用了 IPv6 ？
介紹兩種方式：
1）ifconfig
這個很明顯就能看得出來，有 inet6 addr 字樣說明啟用了 IPv6。
2）lsmod
[root@BJ]# lsmod | grep ipv6
Module Size Used by
ipv6 335951 73 bridge
主要看 Used 這一列，數值 70+，不支持 IPv6 環境 Used 列是 1。
6、問題優化方案總結
經過對 java 堆棧中關鍵線程狀態的分析，明確了問題原因，接下來說下問題解決方案。
第一個問題：
針對從 Http 連接池中獲取不到連接時，可能使線程進入阻塞狀態。
在 HttpClient 客戶端初始化參數配置中增加 connectionRequestTimeout ，獲取連接的超時時間，一般不建議過大，我們設置為 500ms。
設置后，就會調用底層的 condition#awaitUtil(deadline) 方法，當線程無法被 signal 喚醒，到達了 deadline 絕對時間后，線程會自動從等待隊列中被喚醒，加入到 AQS 同步隊列爭搶鎖。
第二個問題：
針對 IPv6 導致的 JVM 進程死鎖問題，有兩種解決方案：
1）操作系統層面禁用 IPv6
編輯 /etc/sysctl.conf 文件
添加下面兩行：
net.ipv6.conf.all.disable_ipv6 = 1
net.ipv6.conf.default.disable_ipv6 = 1
保存，執行 sysctl -p 使其生效。
運行操作系統中執行如下命令直接生效：
sysctl -w net.ipv6.conf.all.disable_ipv6=1
sysctl -w net.ipv6.conf.default.disable_ipv6=1
2）Java 應用程序層面
在應用 JVM 啟動參數上添加 -Djava.net.preferIPv4Stack=true 。
從操作系統層面禁用 IPv6，如果服務器上還部署了其他應用，注意觀察下，如果遇到一些問題可以借助搜索引擎查下。
我們有很多台服務器，都是運維來維護的，所以我采用了第二種方式，直接在 JVM 上增加參數，簡單方便。
最后的總結：
java 堆棧日志中兩個關鍵的 WAITING 線程狀態，先出現了 WAITING (on object monitor)，因 IPv6 問題觸發了 HttpClient 線程池所有線程阻塞。后出現了 WAITING (parking) ，Tomcat 線程接收轉發請求，當請求調用到 HttpClient，因無法獲得 Http 連接資源，且未設置獲取連接的超時時間，造成了大量線程阻塞。
經過對上述兩個問題的優化后，上線觀察很長一段時間，也經歷過比這次問題出現時更高的訪問量，再沒有出現過 JVM 線程阻塞問題。
通過網絡命令行統計，基本不會出現大量的 CLOSE_WAIT 網絡連接狀態。
歡迎關注我的公眾號，掃二維碼關注獲得更多精彩文章，與你一同成長~
