受jvmkill启发的Netflix skunkworks工具jvmquake:用于检测和杀死在GC中花费过多时间的JVM进程 - netflix


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将终止该进程。我们通过挂钩GarbageCollectionStartGarbageCollectionFinish 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数据存储产品中的复杂错误,以便我们的应用程序获得所需的“始终可用”的数据存储。我们已经将许多补丁添加回了社区,我们期待着发现并解决更多的问题。