受jvmkill啟發的Netflix skunkworks工具jvmquake：用於檢測和殺死在GC中花費過多時間的JVM程式 - netflix

banq發表於2019-11-23
JVMMQGC

Netflix的雲資料工程團隊執行各種JVM應用程式，包括諸如Cassandra和Elasticsearch之類的流行資料儲存。儘管我們大多數叢集在分配給它們的記憶體下都能穩定執行，但有時“死亡查詢”或資料儲存本身中的錯誤會導致記憶體使用失控，這可能觸發垃圾回收（GC）迴圈甚至執行JVM記不清。
我們已經對jvmkill進行了補救，以糾正這種情況：jvmkill是使用JVMTI API 在JVM程式中執行的代理。當JVM記憶體不足或無法生成執行緒時，jvmkill介入並殺死整個過程。我們將jvmkill與-XX：HeapDumpOnOutOfMemoryError Hotspot標誌結合使用，以便我們可以在事後再分析堆，目的是瞭解為什麼我們會用光資源。對於我們的應用程式，這種情況是理想的：記憶體不足的JVM無法前進，並且一旦jvmkill介入，systemd將從乾淨的狀態重新啟動失敗的程式。

即使有了jvmkill保護我們，我們仍然遇到JVM的問題，這些JVM幾乎（但不是完全）記憶體不足。這些Java程式一遍又一遍地執行GC，在暫停之間幾乎沒有做任何有用的工作。由於JVM並非100％都沒有資源，因此jvmkill不會發現問題。另一方面，我們的客戶很快注意到其資料儲存節點的吞吐量通常下降了四個數量級。
為了說明這種行為，我們可以透過要求Cassandra幾次將整個資料集載入到記憶體中來演示針對CassandraJVM¹的“死亡查詢”：

cqlsh> PAGING OFF
Disabled Query paging.
cqlsh> SELECT * FROM large_ks.large_table;
OperationTimedOut: errors={}, last_host=some host
cqlsh> SELECT * FROM large_ks.large_table;
Warning: schema version mismatch detected, which might be caused by DOWN nodes; if this is not the case, check the schema versions of your nodes in system.local and system.peers.
Schema metadata was not refreshed. See log for details.


然後，我們使用jstat和GC日誌來觀察機器確實處於GC死亡螺旋中：

$ sudo -u cassandra jstat -gcutil $(pgrep -f Cassandra) 100ms
S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
0.00 100.00 100.00 100.00  97.96  95.10     21    8.678    11  140.498  149.176
0.00 100.00 100.00 100.00  97.96  95.10     21    8.678    11  140.498  149.176
0.00 100.00 100.00 100.00  97.96  95.10     21    8.678    11  140.498  149.176




$ grep "stopped" gclog | tail
2019-03-05T02:59:15.111+0000: 1057.680: Total time for which application threads were stopped: 18.0113457 seconds, Stopping threads took: 0.0001798 seconds
2019-03-05T02:59:16.159+0000: 1058.728: Total time for which application threads were stopped: 1.0472826 seconds, Stopping threads took: 0.0001542 seconds
2019-03-05T02:59:40.461+0000: 1083.030: Total time for which application threads were stopped: 24.3016592 seconds, Stopping threads took: 0.0001809 seconds
2019-03-05T03:00:16.263+0000: 1118.832: Total time for which application threads were stopped: 35.8020625 seconds, Stopping threads took: 0.0001307 seconds
2019-03-05T03:00:51.599+0000: 1154.168: Total time for which application threads were stopped: 35.3361231 seconds, Stopping threads took: 0.0001517 seconds
2019-03-05T03:01:09.470+0000: 1172.039: Total time for which application threads were stopped: 17.8703301 seconds, Stopping threads took: 0.0002151 seconds


在這種情況下，JVM當然無法滿足我們的效能目標，並且恢復的希望很小。這種死亡螺旋一直持續到我們的值班工程師透過殺死受影響的JVM採取行動為止。在被翻頁太多次之後，我們決定出現此問題：
  1. 很容易識別
  2. 有一個簡單的解決方案
  3. 受益於快速干預

解決方案：主動識別並殺死不良的JVM
我們真的很喜歡jvmkill方法，因此我們研究了擴充套件jvmkill來新增所需行為的方法。jvmkill掛接ResourceExhausted JVMTI回撥，根據JVM自己對資源耗盡的評估，向患病的JVM傳送SIGKILL。不幸的是，這個簡單的分類器無法很好地應對灰色故障模式，在這種模式下，JVM花費大量時間進行垃圾回收，但它並沒有耗盡資源。我們還檢查了現有的JVM選項，例如GCHeapFreeLimit，GCTimeLimit，OnOutOfMemoryError，ExitOnOutOfMemoryError和CrashOnOutOfMemoryError。我們發現這些選項或者不能在所有的JVM和垃圾收集器上都一致地工作，難以調整或理解，或者根本就不能在各種情況下工作。由於調整現有JVM的資源消耗分類器的性質不一致且困難/不可能，因此我們決定構建自己的分類器以對其進行補充。
我們的解決方案jvmquake從晚上開始沉迷於“這到底有多難？”的想法開始，我們的想法是，對於任何給定的工作負載，JVM應該花費大部分時間執行程式程式碼，而不是暫停GC 。如果程式時間所佔的比例低於某個水平的時間太長，則JVM顯然是不健康的，應該將其殺死。
我們透過將JVM暫停GC的時間建模為“債務”來實現此想法。如果JVM花200毫秒進行GC，它將增加200毫秒的債務計數器。執行程式程式碼所花費的時間“償還”了所有累積的債務，並在零時停止，因此，如果相同的程式然後執行≥200ms，其債務計數器將降至零。如果JVM花費的執行時間與GCing的時間之比超過1：1（即吞吐量> 50％），則其債務將趨於零。另一方面，如果其吞吐量不到50％，其債務將趨於無限。這種“債務計數器”方法類似於用於跟蹤程式吞吐量的漏斗演算法。在這種情況下，我們以與GC時間成比例的速率新增水，並與應用程式執行時間成比例地刪除它。
隨著JVM債務計數器的增加，我們越來越相信它是不健康的，最終我們獲得了足夠的信心來採取某些措施。
我們確定了一個可調整的閾值，預設值為30秒，這很寬鬆：如果JVM在30秒鐘以上的債務計數器下完成了GC，jvmquake將終止該程式。我們透過掛鉤GarbageCollectionStart和GarbageCollectionFinish JVMTI回撥來測量這些值。
除了債務閾值之外，我們還新增了兩個可調引數：

  • runtime_weight：將乘數應用於花費在執行程式程式碼上的時間，以便我們可以實現除1：1（50％吞吐量）以外的吞吐量目標。例如，runtime_weight為2表示目標是1：2（吞吐量為33％）。更一般而言，x的runtime_weight表示1：x的比率（100％/（x + 1）吞吐量）。伺服器JVM通常以超過95％的吞吐量執行，因此，即使最低50％的吞吐量也是相當保守的。
  • 行動：jvmkill只會向程式傳送SIGKILL，但是在jvmquake中，我們新增了有意OOM JVM以及在SIGKILL之前向自己傳送任意訊號的功能。在下一節中，我們將解釋為什麼可能需要執行這些其他操作。

應用jvmquake之後，如果我們對Cassandra節點執行相同的死亡查詢，就像以前一樣，JVM開始進入GC的死迴圈，但是這次jvmquake注意到JVM累積了30倍的GC債務（以4：1的執行時權重）並停止了JVM。與其像JVM那樣被永久殺死，不如將其永久固定。

1.不要丟掉證據！
當我們使用jvmkill或手動終止JVM時，我們總是有機會分別使用-XX：HeapDumpOnOutOfMemoryError或jmap來收集堆轉儲。這些堆轉儲對於除錯事實之後除錯記憶體洩漏的根本原因至關重要。不幸的是，當jvmquake將SIGKILL傳送到尚未遇到OutOfMemoryError的JVM時，這些方法都不起作用。我們對此的解決方案很簡單：jvmquake觸發時，它會啟用一個執行緒，該執行緒有意將堆上的大型陣列分配給JVM的OOM。這將觸發-XX：HeapDumpOnOutOfMemoryError功能，並最終終止該程式。
但是，這有一個嚴重的問題：Java堆轉儲被寫入並儲存在磁碟上，如果我們反覆執行自動終止操作，可能會填滿磁碟。因此，我們開始研究獲取OS本地核心轉儲而不是JVM特定的堆轉儲的方法。我們意識到，如果我們可以讓一個不健康的JVM傳送自己的SIGABRT而不是SIGKILL，則Linux核心將自動為我們編寫一個核心轉儲。我們喜歡這種方法，因為它是所有語言執行時（包括尤其是node.js和Python）的標準配置，最重要的是因為它允許我們收集非常大的核心/堆轉儲並將其寫入管道，而無需為磁碟提供額外的磁碟空間。儲存它們。
當Linux進行核心轉儲時，預設行為是在崩潰的程式的工作目錄中寫入一個名為“ core”的檔案。為了防止寫入核心檔案會導致磁碟空間不足的情況，Linux對寫入的核心檔案的大小提供了資源限制（ulimit -c）。預設資源限制為零，因此核心根本不寫入任何核心檔案。但是，使用kernel.core_pattern sysctl，可以指定應該將核心轉儲透過管道傳輸到的程式（請參見核心手冊頁中的“將核心轉儲管道傳輸到程式” ）。在此介面之後，我們編寫了一個指令碼來壓縮核心檔案並執行流傳輸上載到S3，並與有關崩潰程式的後設資料一起儲存在S3中。
流上傳完成後，systemd將重新啟動OOMed JVM。這是一個折衷：我們將核心檔案同步上傳到S3，而不必考慮是否需要在本地儲存核心檔案。實際上，我們能夠在不到兩分鐘的時間內可靠地上傳16GB核心轉儲。

2.告訴我出了什麼問題
現在已經捕獲了核心轉儲檔案，我們可以對其進行檢查以顯示出問題的根源–是錯誤的查詢，硬體問題還是配置問題？在大多數情況下，原因可以從所使用的類及其大小來確定。
我們的團隊已將jvmquake部署到我們所有的Java資料儲存中。到目前為止，它已減輕了數十次事件（每次僅幾分鐘），並提高了一些我們最重要的生產資料庫叢集的可用性。此外，流核心轉儲和離線轉換工具使我們能夠除錯和修復Cassandra和Elasticsearch資料儲存產品中的複雜錯誤，以便我們的應用程式獲得所需的“始終可用”的資料儲存。我們已經將許多補丁新增回了社群，我們期待著發現並解決更多的問題。



 

相關文章