Java服务不可用问题排查和解决
前言
作为一名 java 开发者,经常会遇到服务不可用的问题排查。导致问题的原因可能是多种多样的,但是在预先不知道是什么原因导致的服务不可用的时候,通用的排查手段和流程是相似的。
在具体的一些排查方式中涉及到linux的shell命令的使用,但平常又很少用到,导致每次要用到了,都要去重新去搜索。
所以本篇文章记录一下通用的排查方式,并且尽可能得将其流程化,从而方便后续的排查,节省时间成本。
随着一次次的问题排查,经验会更加丰富,排查方式也会不断优化和进步,也能够对JVM和系统资源等方面的知识进一步了解。这篇文章不会写完了之后就封存不动了,而是会持续得更新。
接下来就进入排查流程,并逐一介绍每个流程中要做的事情,
观察监控
问题排查必须要建立在有监控和日志的基础上,否则都没法入手问题调查。观察系统资源和JVM的监控,基本上能够快速找到服务不可用的直接原因和不可用的时间点。
如果连监控都没有,那么首先要做的事情就是应该给Java服务和所在的服务器加上监控。
从监控中我们往往能够看出以下几方面导致服务不可用的原因:
- JVM中的内存不够用了,发生了
OOM - Out of memory
的报错。(通常是堆内存) - 宿主机的CPU资源不够用了
- 宿主机的内存资源不够用了
JVM 监控
首先要查看的就是JVM的内存,下面是一个包含一些JVM内存指标的监控截图。
从这张图中可以很好的看出JVM堆内存和非堆内存的情况。最常关注的就是:
- Eden 新生代内存占用
- Old 老年代内存占用情况
- Metaspace 内存占用情况
如果以上的内存实际占用随着时间不断增加,最终临近相对应的最大值时(used >> max),基本就可以确认是因为内存占用过多导致的服务不可用了。
需要注意的是,不同的虚拟机和垃圾回收对于以上的内存空间的划分不同,但问题的思考上是一致的,即究竟哪块内存占用超出了预设的值。
如果确实发现了内存占用的异常,那么就应该先去看日志记录中,在应用首次不可用那个时间点,是否出现了Out of memory
的报错日志。这一步是为了确定我们基于监控直观获得的初步结论。下文中会介绍如何去查看这些日志。
其实这一步不做也可以,因为根据经验来看,如果直观得发现服务不可用的时刻的内存占用超出max的值,那么基本上就是发生了
OOM
。
接下来继续排查以下内容:
- 是否是因为JVM启动时,设置的堆内存、Metaspace过小导致内存不够用。随着业务的发展、代码功能的不断增加,不再适应现在的应用的内存使用了;
- 如果新生代突然的飙升导致内存超出,那么应该是存在某个大量业务的堆积,或者非常多的数据进入JVM堆内存中。比如线程池中队列的数据堆积,数据库查询一下子查出海量数据。
- 如果是老年代持续地、肉眼可见的上升,那么可能是出现的内存泄漏。比如在一个类中维护了一个static的List,随着时间的增长,这个List越来越大。
如果怀疑是第一点,那么就去重新设置JVM的资源分配即可;针对2、3点则需要进一步进行Dump 文件分析
,后文中会进行介绍。
宿主机监控
如果JVM的监控并没有什么异常,这时候就应该去看看是不是宿主机的问题。一台宿主机上往往会部署很多服务或者运行很多进程,如果其他进程抢占了过多的资源(往往就是CPU、内存),也会导致服务不可用。
下图是一个通过Node Exporter
来采集的系统资源的部分指标的截图:
通过这张图就是很清晰得看出是否是因为系统的资源不够用导致的问题。
解决这类问题,有三个方向上的解决方式:
- 一,是不是宿主机放的服务太多了,不应该把重要的服务和其他一些不稳定的应用放在一起;
- 二,是不是宿主机的配置太差了,可以提升宿主机的资源配置;
- 三,是不是JVM的内存设置太高了,现在的Java服务压根用不了那么大的内存,应该将内存设置小点,否则JVM总想着想系统申请内存资源。
通过日志确定是OOM
集中的日志收集系统
分布式应用部署的如今,基本上现在所有公司都有自己的日志收集系统,很少需要去机器上的log文件上查看日志了。开源常用的有:
- ELK Elasticsearch+Logstash+Kibana
- Skywalking + Elasticsearch
- PLG (Promtail+Loki+Grafana)
在这些日志系统中,选择相应的时间段和Out of memory
的关键字就能判断出是否出现了内存溢出。
机器上查看日志
一般有了日志系统后就不需要再到机器上查看日志了,但有一些日志可能需要单独输出。比如我们有时候需要查看GarbageCollection的情况。
想要将GC的情况输出到特定的日志文件中,可以使用下面的JVM启动参数:
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 -Xloggc:${SYSTEM_LOG_DIR}/gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=14 -XX:GCLogFileSize=100M
先介绍一下这些参数的作用:
-XX:+PrintGCDetails
记录详细的 GC 日志,包括每次垃圾回收的类型(如 Minor GC、Major GC)、内存分代的使用情况(年轻代、老年代等)、回收前后内存的变化等信息。
-XX:+PrintGCDateStamps
为每条 GC 日志添加时间戳。
-XX:+PrintTenuringDistribution
打印每次垃圾回收时晋升年龄分布(Tenuring Distribution),记录哪些对象从年轻代(Eden 区)晋升到老年代,以及晋升的条件(如对象的存活年龄)。
-XX:+PrintHeapAtGC
在每次 GC 开始和结束时,打印详细的堆内存使用情况。
-XX:+PrintReferenceGC
打印对软引用(SoftReference)、弱引用(WeakReference)、虚引用(PhantomReference)对象的回收信息。
-XX:+PrintGCApplicationStoppedTime
记录应用程序因为 GC 停顿的时间。
-XX:+PrintSafepointStatistics
打印 JVM 安全点(Safepoint)相关的统计信息。安全点是 JVM 停止所有应用线程以执行特定任务(如 GC)的点。输出包括进入安全点的时间、原因以及线程的暂停时间等
-XX:PrintSafepointStatisticsCount=<n>
定义打印的安全点统计的次数,如果设置为 1,表示每次达到安全点时打印统计信息。
-Xloggc:<file>
指定 GC 日志输出的文件路径
-XX:+UseGCLogFileRotation
开启 GC 日志文件轮转功能,当日志文件达到指定大小时,会生成一个新文件,而不是覆盖原文件。
-XX:NumberOfGCLogFiles=<n>
设置 GC 日志文件的最大数量。超过此数量时,旧的日志文件会被自动删除,默认值是 10。
-XX:GCLogFileSize=<size>
设置单个 GC 日志文件的大小上限。这里设置为 100M,即日志文件超过 100MB 后会创建新的日志文件。
去log中找到那个时刻的gc情况,就能很好知道在垃圾回收中存在的问题。下面就是一次正常的GC情况的日志记录:
{Heap before GC invocations=410 (full 0): garbage-first heap total 1402880K, used 1252020K [0x0000000080000000, 0x0000000080102ad0, 0x0000000100000000) region size 1024K, 822 young (841728K), 5 survivors (5120K) Metaspace used 214892K, capacity 236788K, committed 237056K, reserved 337920K class space used 26519K, capacity 30174K, committed 30208K, reserved 131072K 2025-01-07T15:49:31.806+0800: 7390.574: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 54001664 bytes, new threshold 15 (max 15) - age 1: 1242448 bytes, 1242448 total - age 2: 240440 bytes, 1482888 total - age 3: 287160 bytes, 1770048 total - age 4: 82880 bytes, 1852928 total - age 5: 55912 bytes, 1908840 total - age 6: 29800 bytes, 1938640 total - age 7: 25160 bytes, 1963800 total - age 8: 231416 bytes, 2195216 total - age 9: 81152 bytes, 2276368 total - age 10: 323552 bytes, 2599920 total - age 11: 225480 bytes, 2825400 total - age 12: 96504 bytes, 2921904 total - age 13: 82944 bytes, 3004848 total - age 14: 262752 bytes, 3267600 total - age 15: 48672 bytes, 3316272 total 2025-01-07T15:49:31.833+0800: 7390.601: [SoftReference, 0 refs, 0.0000535 secs]2025-01-07T15:49:31.833+0800: 7390.601: [WeakReference, 162 refs, 0.0000281 secs]2025-01-07T15:49:31.834+0800: 7390.601: [FinalReference, 427 refs, 0.0017021 secs]2025-01-07T15:49:31.835+0800: 7390.603: [PhantomReference, 5 refs, 0 refs, 0.0000161 secs]2025-01-07T15:49:31.835+0800: 7390.603: [JNI Weak Reference, 0.0001040 secs], 0.0308174 secs] [Parallel Time: 26.4 ms, GC Workers: 4] [GC Worker Start (ms): Min: 7390574.6, Avg: 7390574.6, Max: 7390574.7, Diff: 0.1] [Ext Root Scanning (ms): Min: 3.0, Avg: 3.7, Max: 4.4, Diff: 1.4, Sum: 14.8] [Update RS (ms): Min: 19.9, Avg: 20.5, Max: 21.0, Diff: 1.1, Sum: 82.2] [Processed Buffers: Min: 305, Avg: 327.5, Max: 345, Diff: 40, Sum: 1310] [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Object Copy (ms): Min: 1.5, Avg: 1.8, Max: 2.0, Diff: 0.5, Sum: 7.2] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 26.2, Avg: 26.3, Max: 26.3, Diff: 0.1, Sum: 105.1] [GC Worker End (ms): Min: 7390600.9, Avg: 7390600.9, Max: 7390600.9, Diff: 0.0] [Code Root Fixup: 0.0 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.2 ms] [Other: 4.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.1 ms] [Ref Enq: 0.0 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.2 ms] [Free CSet: 0.7 ms] [Eden: 817.0M(817.0M)->0.0B(816.0M) Survivors: 5120.0K->6144.0K Heap: 1222.7M(1370.0M)->241.4M(1370.0M)] Heap after GC invocations=411 (full 0): garbage-first heap total 1402880K, used 247151K [0x0000000080000000, 0x0000000080102ad0, 0x0000000100000000) region size 1024K, 6 young (6144K), 6 survivors (6144K) Metaspace used 214892K, capacity 236788K, committed 237056K, reserved 337920K class space used 26519K, capacity 30174K, committed 30208K, reserved 131072K } [Times: user=0.11 sys=0.00, real=0.03 secs]
Dump 文件分析
如果怀疑或者确认了是OOM
的问题,那么接下来就是查看究竟是哪些业务导致了OOM
,这时候就需要去分析内存的详细信息了。
Dump 文件下载
如果发生了OOM
,进程就会卡住,此时就应该登录到服务器上去立马把内存导出到文件中,从而进一步分析。
获取Java进程号
ps -ef | grep java
或
jps
dump 内存文件
jmap -dump:format=b,file=dumplog.hprof <pid>
-F选项
用于强制执行堆转储,通常在目标进程(PID 6885)无响应或挂起时使用。如果进程已经完全挂起,jmap命令本身也可能卡住,因为它需要与目标JVM进行交互才能生成dump文件。
使用 VisualVM 查看下载的hprof文件
从中寻找异常(数量多、占用内存大)的对象,一般只要找到了异常的对象,就能知道是哪部分的代码出了问题。
常用的Linux shell命令
查看占用内存最多的进程
如果是系统内存异常,往往需要知道是哪个进程占用内存过多,挤占了JVM所需的内存。
ps -aux | sort -k4nr | head -10
其中k4表示按照内存排序,如果想通过cpu占用排序使用k3。
查看进程状态
ps -p <pid> -o stat
用于查看进程是否异常。
查看进程中占用时间片较长的线程
top -Hp <pid>
查看GC情况
jstat -gcutil <pid> 1000
每隔一秒(1000)来打印一下gc和JVM内存的情况。
到此这篇关于Java服务不可用问题排查和解决的文章就介绍到这了,更多相关Java服务不可用内容请搜索脚本之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持脚本之家!
相关文章
SpringBoot整合EasyExcel实现复杂Excel表格的导入导出
这篇文章主要为大家详细介绍了SpringBoot如何整合EasyExcel实现复杂Excel表格的导入导出功能,文中的示例代码讲解详细,感兴趣的小伙伴可以参考下2023-11-11浅析SpringMVC中的适配器HandlerAdapter
这篇文章主要介绍了SpringMVC中的适配器HandlerAdapter的相关资料,本文给大家介绍的非常详细,对大家的学习或工作具有一定的参考借鉴价值,需要的朋友可以参考下2021-01-01解决异常:Invalid keystore format,springboot配置ssl证书格式不合法问题
这篇文章主要介绍了解决异常:Invalid keystore format,springboot配置ssl证书格式不合法问题,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐教2024-03-03
最新评论