0 前言
最近的文章中,我們詳細介紹了當我們遷移到 Java 21 並將代際 ZGC 作為預設垃圾收集器時,我們的工作負載是如何受益的。虛擬執行緒是我們在這次遷移中興奮採用的另一個特性。
對虛擬執行緒新手,它們被描述為“輕量級執行緒,大大減少編寫、維護和觀察高吞吐量併發應用程式的工作量。”威力來自在阻塞操作發生時,能夠透過延續自動掛起和恢復,從而釋放底層作業系統執行緒以供其他操作重用。在適當的上下文中利用虛擬執行緒可以解鎖更高的效能。
本文討論了在 Java 21 上部署虛擬執行緒的過程中遇到的一個特殊情況。
1 問題
工程師向效能工程和 JVM 生態系統團隊提出了幾份關於間歇性超時和掛起例項的獨立報告。仔細檢查後,我們注意到一組共同的特徵和症狀。在所有受影響的應用程式中,它們都在 Java 21 上執行,使用 SpringBoot 3 和嵌入式 Tomcat 在 REST 端點上提供流量。經歷問題的例項甚至在這些例項上的 JVM 仍然執行時就停止了流量服務。一個清晰的、標誌著這個問題開始的症狀是 closeWait
狀態的套接字數量持續增加:
- Tomcat伺服器的吞吐量在某個時間點突然下降到幾乎為0,表明伺服器可能停止處理新的請求
- 同時,處於closeWait狀態的套接字數量持續增加,這通常表示網路連線沒有被正確關閉
- 這兩個指標的變化是相關的,可能表明存在嚴重的網路或應用程式問題,導致連線無法正常關閉,並最終影響了伺服器的處理能力
2 收集的診斷
停留在 closeWait
狀態的套接字表明遠端對等方關閉了套接字,但本地例項從未關閉它,大概是因為應用程式未能這樣做。這通常表明應用程式處於異常狀態,這種情況下應用程式執行緒轉儲可能會揭示額外的洞察。
為解決這問題,我們首先利用警報系統捕獲處於這種狀態的例項。由於我們定期收集並持久化所有 JVM 工作負載的執行緒轉儲,我們通常可透過檢查這些來自例項的執行緒轉儲來追溯行為。然而,驚訝發現我們所有的執行緒轉儲都顯示一個完全空閒的 JVM,無任何明確的活動。
回顧最近變化,我們發現這些受影響的服務啟用了虛擬執行緒,我們知道虛擬執行緒的呼叫棧不會出現在 jstack
生成的執行緒轉儲中。為了獲得包含虛擬執行緒狀態的更完整的執行緒轉儲,使用 “jcmd Thread.dump_to_file
” 命令。作為最後的手段,我們還從例項中收集了一個堆轉儲。
3 分析
執行緒轉儲揭示了數千個“空白”虛擬執行緒:
#119821 "" virtual
#119820 "" virtual
#119823 "" virtual
#120847 "" virtual
#119822 "" virtual
...
這些是 VT(虛擬執行緒),其中建立了執行緒物件,但尚未開始執行,因此沒有堆疊跟蹤。事實上,空白 VT 的數量與 closeWait
狀態的套接字數量大致相同。為了理解我們所看到的,我們首先需要了解 VT 的工作原理。
虛擬執行緒不是 1:1 對映到專用的 OS 級執行緒。相反,可將其視為計劃到 fork-join 執行緒池中的任務。當虛擬執行緒進入阻塞呼叫時,如等待 Future
,它會放棄它佔據的 OS 執行緒,並簡單地保留在記憶體中,直到它準備恢復。與此同時,OS 執行緒可以被重新分配以執行同一 fork-join 池中的其他 VT。這允許我們將許多 VT 多路複用到僅有的幾個底層 OS 執行緒上。JVM 術語中,底層 OS 執行緒被稱為“載體執行緒”,虛擬執行緒可“安裝”在執行時和“解除安裝”在等待時。
虛擬執行緒的優秀深入描述可以在JEP 444。
在我們的環境下,對 Tomcat 使用了阻塞模型,實際上在請求的生命週期內保留了一個工作執行緒。透過啟用虛擬執行緒,Tomcat 切換到虛擬執行。每個傳入的請求都會建立一個新的虛擬執行緒,該執行緒簡單地被計劃在 Virtual Thread Executor 上作為一個任務。可見 Tomcat 在 這裡 建立了 VirtualThreadExecutor
。
將這些資訊聯絡回我們的問題,症狀對應於 Tomcat 不斷為每個傳入的請求建立一個新的 web 工作 VT,但是沒有可用的 OS 執行緒將它們安裝上去的狀態。
4 Tomcat 為啥卡住了?
OS 執行緒咋了,它們在忙啥?正如 這裡 描述,如虛擬執行緒在 synchronized
塊或方法內執行阻塞操作,它將被固定到底層 OS 執行緒。這正是這裡發生的情況。這是從卡住的例項獲得的執行緒轉儲中的一個相關片段:
#119515 "" virtual
java.base/jdk.internal.misc.Unsafe.park(Native Method)
java.base/java.lang.VirtualThread.parkOnCarrierThread(VirtualThread.java:661)
java.base/java.lang.VirtualThread.park(VirtualThread.java:593)
java.base/java.lang.System$2.parkVirtualThread(System.java:2643)
java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54)
java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:219)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
java.base/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
java.base/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
zipkin2.reporter.internal.CountBoundedQueue.offer(CountBoundedQueue.java:54)
zipkin2.reporter.internal.AsyncReporter$BoundedAsyncReporter.report(AsyncReporter.java:230)
zipkin2.reporter.brave.AsyncZipkinSpanHandler.end(AsyncZipkinSpanHandler.java:214)
brave.internal.handler.NoopAwareSpanHandler$CompositeSpanHandler.end(NoopAwareSpanHandler.java:98)
brave.internal.handler.NoopAwareSpanHandler.end(NoopAwareSpanHandler.java:48)
brave.internal.recorder.PendingSpans.finish(PendingSpans.java:116)
brave.RealSpan.finish(RealSpan.java:134)
brave.RealSpan.finish(RealSpan.java:129)
io.micrometer.tracing.brave.bridge.BraveSpan.end(BraveSpan.java:117)
io.micrometer.tracing.annotation.AbstractMethodInvocationProcessor.after(AbstractMethodInvocationProcessor.java:67)
io.micrometer.tracing.annotation.ImperativeMethodInvocationProcessor.proceedUnderSynchronousSpan(ImperativeMethodInvocationProcessor.java:98)
io.micrometer.tracing.annotation.ImperativeMethodInvocationProcessor.process(ImperativeMethodInvocationProcessor.java:73)
io.micrometer.tracing.annotation.SpanAspect.newSpanMethod(SpanAspect.java:59)
java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
java.base/java.lang.reflect.Method.invoke(Method.java:580)
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:637)
...
這堆疊跟蹤中,進入了 brave.RealSpan.finish(RealSpan.java:134)
的同步。這個虛擬執行緒實際上被固定了 - 它被安裝在一個實際的 OS 執行緒上,即使在等待獲取可重入鎖時也是如此。有 3 個 VT 在這種確切狀態,另一個 VT 被識別為 “<redacted> @DefaultExecutor - 46542
”,它也遵循相同的程式碼路徑。這 4 個虛擬執行緒在等待獲取鎖時被固定。由於應用程式部署在具有 4 個 vCPU 的例項上,支撐 VT 執行的 fork-join 池 也包含 4 個 OS 執行緒。現在我們已經用盡了它們,沒有其他虛擬執行緒可以取得任何進展。這解釋了:
- 為啥 Tomcat 停止處理請求
- 為啥
closeWait
態的套接字數量不斷攀升
事實上,Tomcat 在套接字上接受連線,建立請求以及與之相關的虛擬執行緒,並將此請求/執行緒傳遞給執行器進行處理。然而,新建立的 VT 無法被排程,因為 fork-join 池中的所有 OS 執行緒都被固定並且從未釋放。因此,這些新建立的 VT 被困在佇列中,同時仍然持有套接字。
5 誰擁有鎖?
現在我們知道 VT 正在等待獲取鎖,下一個問題是誰擁有鎖?回答這個問題是理解最初觸發這個條件的關鍵。通常,執行緒轉儲透過 “- locked <0x…> (at …)
” 或 “Locked ownable synchronizers
” 指示誰擁有鎖,但我們的執行緒轉儲中沒有出現這些。事實上,jcmd
生成的執行緒轉儲中沒有包含鎖定/停車/等待資訊。這是 Java 21 的一個限制,並將在未來版本中得到解決。仔細梳理執行緒轉儲,我們發現總共有 6 個執行緒競爭同一個 ReentrantLock
和相關的 Condition
。這六個執行緒中的四個在前一節中詳細說明。這是另一個執行緒:
#119516 "" virtual
java.base/java.lang.VirtualThread.park(VirtualThread.java:582)
java.base/java.lang.System$2.parkVirtualThread(System.java:2643)
java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54)
java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:219)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
java.base/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
java.base/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
zipkin2.reporter.internal.CountBoundedQueue.offer(CountBoundedQueue.java:54)
zipkin2.reporter.internal.AsyncReporter$BoundedAsyncReporter.report(AsyncReporter.java:230)
zipkin2.reporter.brave.AsyncZipkinSpanHandler.end(AsyncZipkinSpanHandler.java:214)
brave.internal.handler.NoopAwareSpanHandler$CompositeSpanHandler.end(NoopAwareSpanHandler.java:98)
brave.internal.handler.NoopAwareSpanHandler.end(NoopAwareSpanHandler.java:48)
brave.internal.recorder.PendingSpans.finish(PendingSpans.java:116)
brave.RealScopedSpan.finish(RealScopedSpan.java:64)
...
請注意,雖然這個執行緒似乎經歷了完成跨度的相同程式碼路徑,但它沒有經過 synchronized
塊。最後是第 6 個執行緒:
#107 "AsyncReporter <redacted>"
java.base/jdk.internal.misc.Unsafe.park(Native Method)
java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:221)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1761)
zipkin2.reporter.internal.CountBoundedQueue.drainTo(CountBoundedQueue.java:81)
zipkin2.reporter.internal.AsyncReporter$BoundedAsyncReporter.flush(AsyncReporter.java:241)
zipkin2.reporter.internal.AsyncReporter$Flusher.run(AsyncReporter.java:352)
java.base/java.lang.Thread.run(Thread.java:1583)
這實際上是一個普通的平臺執行緒,而不是虛擬執行緒。特別注意這個堆疊跟蹤中的行號,這個執行緒似乎在內部 acquire()
方法 之後 阻塞了 完成等待。換句話說,這個呼叫執行緒在進入 awaitNanos()
時擁有鎖。我們知道鎖是在這裡明確獲取的 here。然而,當等待完成時,它無法重新獲取鎖。總結我們的執行緒轉儲分析:
Thread ID/name | Virtual? | “synchronized” block? | Pinned? | Waiting for the lock? |
---|---|---|---|---|
#119513 "" | Yes | Yes | Yes | Yes |
#119514 "" | Yes | Yes | Yes | Yes |
#119515 "" | Yes | Yes | Yes | Yes |
#119517 "<redacted> @DefaultExecutor - 46542" | Yes | Yes | Yes | Yes |
#119516 "" | Yes | No | No | Yes |
#107 "AsyncReporter |
No | No | N/A | Yes |
在分析了鎖的爭奪情況後,我們發現有5個虛擬執行緒和1個常規執行緒正在等待鎖。其中4個虛擬執行緒被固定在了fork-join池的OS執行緒上。儘管如此,我們仍然沒有關於誰擁有該鎖的資訊。由於無法從執行緒轉儲中獲取更多資訊,我們合乎邏輯的下一步是檢視堆轉儲並內省鎖的狀態。
6 檢查鎖
在堆轉儲中找到鎖是相對直接的。使用出色的Eclipse MAT工具,我們檢查了AsyncReporter非虛擬執行緒的堆疊上的物件,以識別鎖物件。推理鎖的當前狀態可能是我們調查中最棘手的部分。大多數相關程式碼都可以在AbstractQueuedSynchronizer.java
中找到。雖然我們不聲稱完全理解其內部工作原理,但我們逆向工程了足夠的資訊以匹配我們在堆轉儲中看到的內容。下面的圖表說明了我們的發現:
首先,exclusiveOwnerThread
欄位為null
(2),表示沒有人擁有該鎖。我們在列表的頭部有一個“空”的ExclusiveNode
(3)(waiter
為null
且status
已清除),後面是另一個ExclusiveNode
,其waiter
指向爭奪鎖的虛擬執行緒之一——#119516(4)。我們發現唯一清除exclusiveOwnerThread
欄位的地方是在ReentrantLock.Sync.tryRelease()
方法中(原始碼連結)。在那裡,我們還設定了state = 0
,與我們在堆轉儲中看到的狀態相匹配(1)。
考慮到這一點,我們追溯了釋放鎖的程式碼路徑。在成功呼叫tryRelease()
之後,持有鎖的執行緒嘗試向列表中的下一個等待者發出訊號。此時,即使鎖的所有權實際上已經釋放,持有鎖的執行緒仍然在列表的頭部。列表中的下一個節點指向即將獲取鎖的執行緒。
為了理解這種訊號是如何工作的,讓我們看看AbstractQueuedSynchronizer.acquire()
方法中的鎖定獲取路徑。極度簡化地說,它是一個無限迴圈,執行緒嘗試獲取鎖,如果嘗試不成功,則停車:
while(true) {
if (tryAcquire()) {
return; // 鎖已獲取
}
park();
}
當持有鎖的執行緒釋放鎖併發出訊號以取消阻塞下一個等待執行緒時,被取消阻塞的執行緒將再次遍歷這個迴圈,給它又一次獲取鎖的機會。事實上,我們的執行緒轉儲表明我們所有的等待執行緒都停在了第754行。一旦被取消阻塞,成功獲取鎖的執行緒最終將進入這段程式碼塊中,有效地重置列表的頭部並清除對等待者的引用。
更簡潔地重新陳述,擁有鎖的執行緒被列表的頭部節點引用。釋放鎖會通知列表中的下一個節點,而獲取鎖會將列表的頭部重置為當前節點。這意味著我們在堆轉儲中看到的內容反映了一個執行緒已經釋放了鎖但下一個執行緒尚未獲取它的狀態。這是一個本應是瞬態的奇怪中間狀態,但我們的JVM卻卡在了這裡。我們知道執行緒#119516已經被通知並且即將獲取鎖,因為我們在列表頭部識別出的ExclusiveNode
狀態。然而,執行緒轉儲顯示執行緒#119516繼續等待,就像其他爭奪相同鎖的執行緒一樣。我們如何調和執行緒和堆轉儲之間所看到的情況?
7 無處執行的鎖
知道執行緒#119516實際上已經被通知,我們回到執行緒轉儲中重新檢查執行緒的狀態。回想一下,我們總共有6個執行緒在等待鎖,其中4個虛擬執行緒每個都被固定在OS執行緒上。這4個執行緒在獲取鎖並退出同步塊之前不會放棄它們的OS執行緒。#107 "AsyncReporter <redacted>"
是一個常規平臺執行緒,所以如果它獲取了鎖,沒有什麼可以阻止它繼續進行。這讓我們剩下最後一個執行緒:#119516
。它是一個VT,但它沒有被固定在OS執行緒上。即使它被通知取消停車,它也無法繼續,因為fork-join池中沒有更多的OS執行緒可以排程它。正是這裡發生的情況——儘管#119516
被訊號取消停車,它不能離開停車狀態,因為fork-join池被其他4個等待獲取相同鎖的VT佔據。那些被固定的VT在獲取鎖之前都不能繼續。這是經典死鎖問題的變體,但我們有一個鎖和一個由fork-join池所代表的4個許可的訊號量。
現在我們知道確切發生了什麼,很容易想出一個可重現的測試用例。
8 結論
虛擬執行緒預計將透過減少與執行緒建立和上下文切換相關的開銷來提高效能。儘管Java 21還有一些尖銳的邊緣,虛擬執行緒在很大程度上實現了它們的承諾。在我們尋求更高效能的Java應用程式的過程中,我們看到進一步採用虛擬執行緒是實現該目標的關鍵。我們期待Java 23及以後,它帶來了大量的升級,希望解決虛擬執行緒和鎖定原語之間的整合問題。
這次探索僅突出了效能工程師解決的問題型別之一。我們希望這種對我們解決問題方法的一瞥對其他人在未來的調查中具有價值。
關注我,緊跟本系列專欄文章,咱們下篇再續!
作者簡介:魔都架構師,多家大廠後端一線研發經驗,在分散式系統設計、資料平臺架構和AI應用開發等領域都有豐富實踐經驗。
各大技術社群頭部專家博主。具有豐富的引領團隊經驗,深厚業務架構和解決方案的積累。
負責:
- 中央/分銷預訂系統效能最佳化
- 活動&券等營銷中臺建設
- 交易平臺及資料中臺等架構和開發設計
- 車聯網核心平臺-物聯網連線平臺、大資料平臺架構設計及最佳化
- LLM Agent應用開發
- 區塊鏈應用開發
- 大資料開發挖掘經驗
- 推薦系統專案
目前主攻市級軟體專案設計、構建服務全社會的應用系統。
參考:
- 程式設計嚴選網
本文由部落格一文多發平臺 OpenWrite 釋出!