JVM的基础入门(上):https://developer.aliyun.com/article/1480669
▐ 配置垃圾收集器
- 首先是内存大小问题,基本上每一个内存区域我都会设置一个上限,来避免溢出问题,比如元空间。
- 通常,堆空间我会设置成操作系统的 2/3,超过 8GB 的堆,优先选用 G1。
- 然后我会对 JVM 进行初步优化,比如根据老年代的对象提升速度,来调整年轻代和老年代之间的比例。
- 依据系统容量、访问延迟、吞吐量等进行专项优化,我们的服务是高并发的,对 STW 的时间敏感。
- 我会通过记录详细的 GC 日志,来找到这个瓶颈点,借用 GCeasy 这样的日志分析工具,定位问题。
▐ JVM性能调优
对应进程的JVM状态以定位问题和解决问题并作出相应的优化
常用命令:jps、jinfo、jstat、jstack、jmapjps:查看java进程及相关信息
jps -l 输出jar包路径,类全名 jps -m 输出main参数 jps -v 输出JVM参数
jinfo:查看JVM参数
jinfo 11666 jinfo -flags 11666 Xmx、Xms、Xmn、MetaspaceSize
jstat:查看JVM运行时的状态信息,包括内存状态、垃圾回收
jstat [option] LVMID [interval] [count]其中LVMID是进程id,interval是打印间隔时间(毫秒),count是打印次数(默认一直打印) option参数解释:-gc 垃圾回收堆的行为统计-gccapacity 各个垃圾回收代容量(young,old,perm)和他们相应的空间统计-gcutil 垃圾回收统计概述-gcnew 新生代行为统计-gcold 年老代和永生代行为统计
jstack:查看JVM线程快照,jstack命令可以定位线程出现长时间卡顿的原因,例如死锁,死循环
jstack [-l] <pid> (连接运行中的进程) option参数解释:-F 当使用jstack <pid>无响应时,强制输出线程堆栈。-m 同时输出java和本地堆栈(混合模式)-l 额外显示锁信息
jmap:可以用来查看内存信息(配合jhat使用)
jmap [option] <pid> (连接正在执行的进程)option参数解释:-heap 打印java heap摘要-dump:<dump-options> 生成java堆的dump文件
▐ JDK新特性
JDK8
支持 Lamda 表达式、集合的 stream 操作、提升HashMap性能
JDK9
//Stream API中iterate方法的新重载方法,可以指定什么时候结束迭代IntStream.iterate(1, i -> i < 100, i -> i + 1).forEach(System.out::println);
默认G1垃圾回收器
JDK10:其重点在于通过完全GC并行来改善G1最坏情况的等待时间。
JDK11:
- ZGC (并发回收的策略) 4TB
- 用于 Lambda 参数的局部变量语法
JDK12:Shenandoah GC (GC 算法)停顿时间和堆的大小没有任何关系,并行关注停顿响应时间。
JDK13:增加ZGC以将未使用的堆内存返回给操作系统,16TB
JDK14:
- 删除cms垃圾回收器、弃用ParallelScavenge+SerialOldGC垃圾回收算法组合。
- 将ZGC垃圾回收器应用到macOS和windows平台。
线上故障排查
▐ 硬件故障排查
如果一个实例发生了问题,根据情况选择,要不要着急去重启。如果出现的CPU、内存飙高或者日志里出现了OOM异常。
第一步是隔离,第二步是保留现场,第三步才是问题排查。隔离就是把你的这台机器从请求列表里摘除,比如把 nginx 相关的权重设成零。现场保留瞬时态和历史态 查看比如 CPU、系统内存等,通过历史状态可以体现一个趋势性问题,而这些信息的获取一般依靠监控系统的协作。
保留信息
(1)系统当前网络连接
ss -antp > $DUMP_DIR/ss.dump 2>&1
使用 ss 命令而不是 netstat 的原因,是因为 netstat 在网络连接非常多的情况下,执行非常缓慢。
后续的处理,可通过查看各种网络连接状态的梳理,来排查 TIME_WAIT 或者 CLOSE_WAIT,或者其他连接过高的问题,非常有用。
(2)网络状态统计
netstat -s > $DUMP_DIR/netstat-s.dump 2>&1
它能够按照各个协议进行统计输出,对把握当时整个网络状态,有非常大的作用。
sar -n DEV 1 2 > $DUMP_DIR/sar-traffic.dump 2>&1
在一些速度非常高的模块上,比如 Redis、Kafka,就经常发生跑满网卡的情况。表现形式就是网络通信非常缓慢。
(3)进程资源
lsof -p $PID > $DUMP_DIR/lsof-$PID.dump
通过查看进程,能看到打开了哪些文件,可以以进程的维度来查看整个资源的使用情况,包括每条网络连接、每个打开的文件句柄。同时,也可以很容易的看到连接到了哪些服务器、使用了哪些资源。这个命令在资源非常多的情况下,输出稍慢,请耐心等待。
(4)CPU 资源
mpstat > $DUMP_DIR/mpstat.dump 2>&1vmstat 1 3 > $DUMP_DIR/vmstat.dump 2>&1sar -p ALL > $DUMP_DIR/sar-cpu.dump 2>&1uptime > $DUMP_DIR/uptime.dump 2>&1
主要用于输出当前系统的 CPU 和负载,便于事后排查。
(5)I/O 资源
iostat -x > $DUMP_DIR/iostat.dump 2>&1
一般,以计算为主的服务节点,I/O 资源会比较正常,但有时也会发生问题,比如日志输出过多,或者磁盘问题等。此命令可以输出每块磁盘的基本性能信息,用来排查 I/O 问题。在第 8 课时介绍的 GC 日志分磁盘问题,就可以使用这个命令去发现。
(6)内存问题
free -h > $DUMP_DIR/free.dump 2>&1
free 命令能够大体展现操作系统的内存概况,这是故障排查中一个非常重要的点,比如 SWAP 影响了 GC,SLAB 区挤占了 JVM 的内存。
(7)其他全局
ps -ef > $DUMP_DIR/ps.dump 2>&1dmesg > $DUMP_DIR/dmesg.dump 2>&1sysctl -a > $DUMP_DIR/sysctl.dump 2>&1
dmesg 是许多静悄悄死掉的服务留下的最后一点线索。当然,ps 作为执行频率最高的一个命令,由于内核的配置参数,会对系统和 JVM 产生影响,所以我们也输出了一份。
(8)进程快照,最后的遗言(jinfo)
${JDK_BIN}jinfo $PID > $DUMP_DIR/jinfo.dump 2>&1
此命令将输出 Java 的基本进程信息,包括环境变量和参数配置,可以查看是否因为一些错误的配置造成了 JVM 问题。
(9)dump 堆信息
${JDK_BIN}jstat -gcutil $PID > $DUMP_DIR/jstat-gcutil.dump 2>&1${JDK_BIN}jstat -gccapacity $PID > $DUMP_DIR/jstat-gccapacity.dump 2>&1
jstat 将输出当前的 gc 信息。一般,基本能大体看出一个端倪,如果不能,可将借助 jmap 来进行分析。
(10)堆信息
${JDK_BIN}jmap $PID > $DUMP_DIR/jmap.dump 2>&1${JDK_BIN}jmap -heap $PID > $DUMP_DIR/jmap-heap.dump 2>&1${JDK_BIN}jmap -histo $PID > $DUMP_DIR/jmap-histo.dump 2>&1${JDK_BIN}jmap -dump:format=b,file=$DUMP_DIR/heap.bin $PID > /dev/null 2>&1
jmap 将会得到当前 Java 进程的 dump 信息。如上所示,其实最有用的就是第 4 个命令,但是前面三个能够让你初步对系统概况进行大体判断。因为,第 4 个命令产生的文件,一般都非常的大。而且,需要下载下来,导入 MAT 这样的工具进行深入分析,才能获取结果。这是分析内存泄漏一个必经的过程。
(11)JVM 执行栈
${JDK_BIN}jstack $PID > $DUMP_DIR/jstack.dump 2>&1
jstack 将会获取当时的执行栈。一般会多次取值,我们这里取一次即可。这些信息非常有用,能够还原 Java 进程中的线程情况。
top -Hp $PID -b -n 1 -c > $DUMP_DIR/top-$PID.dump 2>&1
为了能够得到更加精细的信息,我们使用 top 命令,来获取进程中所有线程的 CPU 信息,这样,就可以看到资源到底耗费在什么地方了。
(12)高级替补
kill -3 $PID
有时候,jstack 并不能够运行,有很多原因,比如 Java 进程几乎不响应了等之类的情况。我们会尝试向进程发送 kill -3 信号,这个信号将会打印 jstack 的 trace 信息到日志文件中,是 jstack 的一个替补方案。
gcore -o $DUMP_DIR/core $PID
对于 jmap 无法执行的问题,也有替补,那就是 GDB 组件中的 gcore,将会生成一个 core 文件。我们可以使用如下的命令去生成 dump:
${JDK_BIN}jhsdb jmap --exe ${JDK}java --core $DUMP_DIR/core --binaryheap
内存泄漏的现象
稍微提一下 jmap 命令,它在 9 版本里被干掉了,取而代之的是 jhsdb,你可以像下面的命令一样使用。
jhsdb jmap --heap --pid 37340jhsdb jmap --pid 37288jhsdb jmap --histo --pid 37340jhsdb jmap --binaryheap --pid 37340
一般内存溢出,表现形式就是 Old 区的占用持续上升,即使经过了多轮 GC 也没有明显改善。比如ThreadLocal里面的GC Roots,内存泄漏的根本就是,这些对象并没有切断和 GC Roots 的关系,可通过一些工具,能够看到它们的联系。
▐ 报表异常 | JVM调优
有一个报表系统,频繁发生内存溢出,在高峰期间使用时,还会频繁的发生拒绝服务,由于大多数使用者是管理员角色,所以很快就反馈到研发这里。
业务场景是由于有些结果集的字段不是太全,因此需要对结果集合进行循环,并通过 HttpClient 调用其他服务的接口进行数据填充。使用 Guava 做了 JVM 内缓存,但是响应时间依然很长。
初步排查,JVM 的资源太少。接口 A 每次进行报表计算时,都要涉及几百兆的内存,而且在内存里驻留很长时间,有些计算又非常耗 CPU,特别的“吃”资源。而我们分配给 JVM 的内存只有 3 GB,在多人访问这些接口的时候,内存就不够用了,进而发生了 OOM。在这种情况下,没办法,只有升级机器。把机器配置升级到 4C8G,给 JVM 分配 6GB 的内存,这样 OOM 问题就消失了。但随之而来的是频繁的 GC 问题和超长的 GC 时间,平均 GC 时间竟然有 5 秒多。
进一步,由于报表系统和高并发系统不太一样,它的对象,存活时长大得多,并不能仅仅通过增加年轻代来解决;而且,如果增加了年轻代,那么必然减少了老年代的大小,由于 CMS 的碎片和浮动垃圾问题,我们可用的空间就更少了。虽然服务能够满足目前的需求,但还有一些不太确定的风险。
第一,了解到程序中有很多缓存数据和静态统计数据,为了减少 MinorGC 的次数,通过分析 GC 日志打印的对象年龄分布,把 MaxTenuringThreshold 参数调整到了 3(特殊场景特殊的配置)。这个参数是让年轻代的这些对象,赶紧回到老年代去,不要老呆在年轻代里。第二,我们的 GC 时间比较长,就一块开了参数 CMSScavengeBeforeRemark,使得在 CMS remark 前,先执行一次 Minor GC 将新生代清掉。同时配合上个参数,其效果还是比较好的,一方面,对象很快晋升到了老年代,另一方面,年轻代的对象在这种情况下是有限的,在整个 MajorGC 中占的时间也有限。第三,由于缓存的使用,有大量的弱引用,拿一次长达 10 秒的 GC 来说。我们发现在 GC 日志里,处理 weak refs 的时间较长,达到了 4.5 秒。这里可以加入参数 ParallelRefProcEnabled 来并行处理Reference,以加快处理速度,缩短耗时。
优化之后,效果不错,但并不是特别明显。经过评估,针对高峰时期的情况进行调研,我们决定再次提升机器性能,改用 8core16g 的机器。但是,这带来另外一个问题。
高性能的机器带来了非常大的服务吞吐量,通过 jstat 进行监控,能够看到年轻代的分配速率明显提高,但随之而来的 MinorGC 时长却变的不可控,有时候会超过 1 秒。累积的请求造成了更加严重的后果。
这是由于堆空间明显加大造成的回收时间加长。为了获取较小的停顿时间,我们在堆上改用了 G1 垃圾回收器,把它的目标设定在 200ms。G1 是一款非常优秀的垃圾收集器,不仅适合堆内存大的应用,同时也简化了调优的工作。通过主要的参数初始和最大堆空间、以及最大容忍的 GC 暂停目标,就能得到不错的性能。修改之后,虽然 GC 更加频繁了一些,但是停顿时间都比较小,应用的运行较为平滑。
到目前为止,也只是勉强顶住了已有的业务,但是,这时候领导层面又发力,要求报表系统可以支持未来两年业务10到100倍的增长,并保持其可用性,但是这个“千疮百孔”的报表系统,稍微一压测,就宕机,那如何应对十倍百倍的压力呢 ? 硬件即使可以做到动态扩容,但是毕竟也有极限。
使用 MAT 分析堆快照,发现很多地方可以通过代码优化,那些占用内存特别多的对象:
- select * 全量排查,只允许获取必须的数据;
- 报表系统中cache实际的命中率并不高,将Guava 的 Cache 引用级别改成弱引用(WeakKeys);
- 限制报表导入文件大小,同时拆分用户超大范围查询导出请求。
每一步操作都使得JVM使用变得更加可用,一系列优化以后,机器相同压测数据性能提升了数倍。
▐ 大屏异常 | JUC调优
有些数据需要使用 HttpClient 来获取进行补全。提供数据的服务提供商有的响应时间可能会很长,也有可能会造成服务整体的阻塞。
接口 A 通过 HttpClient 访问服务 2,响应 100ms 后返回;接口 B 访问服务 3,耗时 2 秒。HttpClient 本身是有一个最大连接数限制的,如果服务 3 迟迟不返回,就会造成 HttpClient 的连接数达到上限,概括来讲,就是同一服务,由于一个耗时非常长的接口,进而引起了整体的服务不可用。
这个时候,通过 jstack 打印栈信息,会发现大多数竟然阻塞在了接口 A 上,而不是耗时更长的接口 B,这个现象起初十分具有迷惑性,不过经过分析后,我们猜想其实是因为接口 A 的速度比较快,在问题发生点进入了更多的请求,它们全部都阻塞住的同时被打印出来了。
为了验证这个问题,我搭建了一个demo 工程,模拟了两个使用同一个 HttpClient 的接口。fast 接口用来访问百度,很快就能返回;slow 接口访问谷歌,由于众所周知的原因,会阻塞直到超时,大约 10 s。利用ab对两个接口进行压测,同时使用 jstack 工具 dump 堆栈。首先使用 jps 命令找到进程号,然后把结果重定向到文件(可以参考 10271.jstack 文件)。
过滤一下 nio 关键字,可以查看 tomcat 相关的线程,足足有 200 个,这和 Spring Boot 默认的 maxThreads 个数不谋而合。更要命的是,有大多数线程,都处于 BLOCKED 状态,说明线程等待资源超时。通过grep fast | wc -l 分析,确实200个中有150个都是blocked的fast的进程。
问题找到了,解决方式就顺利成章了。
- fast和slow争抢连接资源,通过线程池限流或者熔断处理
- 有时候slow的线程也不是一直slow,所以就得加入监控
- 使用带countdownLaunch对线程的执行顺序逻辑进行控制
▐ 接口延迟 | SWAP调优
有一个关于服务的某个实例,经常发生服务卡顿。由于服务的并发量是比较高的,每多停顿 1 秒钟,几万用户的请求就会感到延迟。
我们统计、类比了此服务其他实例的 CPU、内存、网络、I/O 资源,区别并不是很大,所以一度怀疑是机器硬件的问题。
接下来我们对比了节点的 GC 日志,发现无论是 Minor GC,还是 Major GC,这个节点所花费的时间,都比其他实例长得多。
通过仔细观察,我们发现在 GC 发生的时候,vmstat 的 si、so 飙升的非常严重,这和其他实例有着明显的不同。
使用 free 命令再次确认,发现 SWAP 分区,使用的比例非常高,引起的具体原因是什么呢?
更详细的操作系统内存分布,从 /proc/meminfo 文件中可以看到具体的逻辑内存块大小,有多达 40 项的内存信息,这些信息都可以通过遍历 /proc 目录的一些文件获取。我们注意到 slabtop 命令显示的有一些异常,dentry(目录高速缓冲)占用非常高。
问题最终定位到是由于某个运维工程师删除日志时,定时执行了一句命令:find / | grep "xxx.log"
他是想找一个叫做 要被删除 的日志文件,看看在哪台服务器上,结果,这些老服务器由于文件太多,扫描后这些文件信息都缓存到了 slab 区上。而服务器开了 swap,操作系统发现物理内存占满后,并没有立即释放 cache,导致每次 GC 都要和硬盘打一次交道。
解决方式就是关闭 SWAP 分区。swap 是很多性能场景的万恶之源,建议禁用。在高并发 SWAP 绝对能让你体验到它魔鬼性的一面:进程倒是死不了了,但 GC 时间长的却让人无法忍受。
▐ 内存溢出 | Cache调优
有一次线上遇到故障,重新启动后,使用 jstat 命令,发现 Old 区一直在增长。我使用 jmap 命令,导出了一份线上堆栈,然后使用 MAT 进行分析,通过对 GC Roots 的分析,发现了一个非常大的 HashMap 对象,这个原本是其他同事做缓存用的,但是做了一个无界缓存,没有设置超时时间或者 LRU 策略,在使用上又没有重写key类对象的hashcode和equals方法,对象无法取出也直接造成了堆内存占用一直上升,后来,将这个缓存改成 guava 的 Cache,并设置了弱引用,故障就消失了。 关于文件处理器的应用,在读取或者写入一些文件之后,由于发生了一些异常,close 方法又没有放在 finally块里面,造成了文件句柄的泄漏。由于文件处理十分频繁,产生了严重的内存泄漏问题。
内存溢出是一个结果,而内存泄漏是一个原因。内存溢出的原因有内存空间不足、配置错误等因素。一些错误的编程方式,不再被使用的对象、没有被回收、没有及时切断与 GC Roots 的联系,这就是内存泄漏。
举个例子,有团队使用了 HashMap 做缓存,但是并没有设置超时时间或者 LRU 策略,造成了放入 Map 对象的数据越来越多,而产生了内存泄漏。
再来看一个经常发生的内存泄漏的例子,也是由于 HashMap 产生的。代码如下,由于没有重写 Key 类的 hashCode 和 equals 方法,造成了放入 HashMap 的所有对象都无法被取出来,它们和外界失联了。所以下面的代码结果是 null。
//leak exampleimport java.util.HashMap;import java.util.Map;public class HashMapLeakDemo { public static class Key { String title; public Key(String title) { this.title = title; }}public static void main(String[] args) { Map<Key, Integer> map = new HashMap<>(); map.put(new Key("1"), 1); map.put(new Key("2"), 2); map.put(new Key("3"), 2); Integer integer = map.get(new Key("2")); System.out.println(integer); }}
即使提供了 equals 方法和 hashCode 方法,也要非常小心,尽量避免使用自定义的对象作为 Key。
再看一个例子,关于文件处理器的应用,在读取或者写入一些文件之后,由于发生了一些异常,close 方法又没有放在 finally 块里面,造成了文件句柄的泄漏。由于文件处理十分频繁,产生了严重的内存泄漏问题。
▐ CPU飙高 | 死循环
我们有个线上应用,单节点在运行一段时间后,CPU 的使用会飙升,一旦飙升,一般怀疑某个业务逻辑的计算量太大,或者是触发了死循环(比如著名的 HashMap 高并发引起的死循环),但排查到最后其实是 GC 的问题。
(1)使用 top 命令,查找到使用 CPU 最多的某个进程,记录它的 pid。使用 Shift + P 快捷键可以按 CPU 的使用率进行排序。
top
(2)再次使用 top 命令,加 -H 参数,查看某个进程中使用 CPU 最多的某个线程,记录线程的 ID。
top -Hp $pid
(3)使用 printf 函数,将十进制的 tid 转化成十六进制。
printf %x $tid
(4)使用 jstack 命令,查看 Java 进程的线程栈。
jstack $pid >$pid.log
(5)使用 less 命令查看生成的文件,并查找刚才转化的十六进制 tid,找到发生问题的线程上下文。
less $pid.log
我们在 jstack 日志搜关键字DEAD,以及中找到了 CPU 使用最多的几个线程id。
可以看到问题发生的根源,是我们的堆已经满了,但是又没有发生 OOM,于是 GC 进程就一直在那里回收,回收的效果又非常一般,造成 CPU 升高应用假死。接下来的具体问题排查,就需要把内存 dump 一份下来,使用 MAT 等工具分析具体原因了。