由一次線上故障來理解下TCP三握、四揮; Java堆棧分析到源碼的探秘
- 2019 年 11 月 21 日
- 筆記
本文導讀:
- 生產故障場景介紹
- 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
網路連接狀態。



解鎖更多精彩
與你一同成長