Java线上问题排查流程&方案

系统运行一段时间后很慢如何排查？

​ 如果说程序上线一段时间后运行特别慢，则考虑是否同一时间段出现大量请求导致阻塞（❌如果是在请求正常的情况下）

​ 排除思路：由外到内，结合系统日志跟踪，排除外部原因，然后跟踪内部因素

​

​ 可以结合实际业务场景从多个维度去思考：关注点：监控排查、代码排查、数据库分析、系统资源、外部依赖、应用架构

• 性能监控和排查（linux指令查看系统运行、宝塔面板查看）：查看程序的CPU、内存、磁盘I/O和网络使用情况，随后跟踪线上日志定位异常信息

​ Linux 常用的性能分析工具使用包括 : top(cpu)、free(内存)、df(磁盘)、dstat(网络流量)、pstack、vmstat、strace(底层系统调用)

• 程序排查、代码审查：排查是客户端还是服务端问题，进一步检查程序代码编写逻辑相关内容（一些业务逻辑的循环嵌套、频繁访问数据库操作等）

​ 之前在szwh一体化平台这个项目中就会遇到这块的内容，外包的同事不了解flowable流程跟踪的机制，于是可能在程序代码里面编写了一些自定义不太规范的实现，导致线程阻塞整个卡住（例如一些大数据表关联筛选的for内嵌多层没有进行优化、业务操作频繁访问数据库等）

• 数据库分析：慢查询日志跟踪=》慢查询语句执行计划分析=》适当建立索引、避免索引失效场景、引入查询缓存等

​ 一些业务场景可能会涉及到一些数据检索、多表联查，对于这类的查询语句则可分析相应的语句执行效率和优化；

​ 像是MyBatis的分页概念：逻辑分页和物理分页，默认是逻辑分页（一次性从数据库读取所有数据，然后根据分页参数去进行逻辑分页操作），引入MyBatis的分页插件则可将原有的逻辑分页调整为物理分页，将分页在SQL层面去做

• 系统资源检查：检查服务器资源是否到达瓶颈、检查文件资源的占用情况（会不会是程序代码一些文件、数据库资源没有得到有效的释放）

​ 考虑是否出现一些文件资源或者数据库资源没有得到及时释放导致，如果是基于这些问题则相应要一一排查。例如LocalThread触发的内存泄漏问题（要及时remove）、数据库连接被占用没有及时关闭（数据库连接池配置）、文件资源没有正确关闭等都会造成程序运行缓慢

​ 例如eoas系统中需要存储一些文件信息，一段时间后可能文件存储占比比较大导致占用了大量资源

• 外部服务依赖：如果存在和第三方接口对接的情况（API接口调用、第三方库等），要考虑对方服务的响应时间和稳定性

​ 像是fhyd项目，在对企业资质进行筛选的时候会调用到外部数据接口获取到企业的工商信息，还会调用挖掘科接口进行数据测额，这个时候就要排查第三方的接口的稳定性和响应时间

• 应用架构：单点故障排查（确认是否存在性能瓶颈）、对于微服务架构则检查服务间通信是否高效？是否存在雪崩？

排查原因：

性能监控与分析：

• 使用性能监控工具（如：New Relic, AppDynamics, Prometheus等）监控程序的CPU、内存、磁盘I/O和网络使用情况
• 分析应用程序日志，查找异常错误或警告

数据库分析：

• 检查数据库的慢查询日志，找出执行效率低下的SQL语句
• 分析数据库的索引使用情况，是否存在索引缺失或索引不当
• 查看数据库的连接池和并发情况，是否存在连接泄露或过度的并发访问

代码审查：

• 审查代码，特别是新近上线的功能，检查是否存在性能瓶颈或内存泄露
• 分析程序中的循环和递归调用，检查是否有可以优化的地方

系统资源检查：

• 检查服务器资源是否达到瓶颈，如CPU利用率、内存使用情况、磁盘空间和I/O性能
• 检查操作系统级别的限制，如文件句柄数、网络连接数等

外部服务依赖：

• 如果程序依赖外部服务（如API调用、第三方库等），检查这些服务的响应时间和稳定性

应用架构评估：

• 分析应用架构，是否存在单点故障或性能瓶颈的组件

• 对于微服务架构，检查服务间的通信是否高效，是否存在服务雪崩

解决方案：

优化SQL语句：

• 优化慢查询，添加或改进索引。
• 避免使用SELECT *，只获取必要的列。
• 使用批量操作减少数据库的I/O操作。

代码优化：

• 优化循环和递归，减少不必要的计算和内存分配。
• 使用更高效的数据结构和算法。

缓存策略：

• 引入缓存机制，如Redis或Memcached，减少数据库的负载。
• 优化缓存策略，如合理设置缓存大小和过期时间。

负载均衡：

• 使用负载均衡器分散请求，避免单点服务器过载。
• 对于分布式系统，合理分配数据和请求。

资源扩展：

• 根据需要增加服务器资源，如增加内存、CPU等。
• 对于云服务，可以弹性扩展资源以应对高负载。

定期维护：

• 定期对数据库进行维护操作，如索引重建、数据碎片整理等。
• 定期更新和优化代码，移除不再使用的代码和依赖。

监控与报警：

• 完善监控体系，及时发现并报警性能问题。
• 设置合理的性能阈值，自动触发报警。

通过上述步骤，可以逐步排查并解决程序运行缓慢的问题。重要的是要持续监控应用程序的性能，并定期进行优化和维护

Java服务常见线上问题

​ 综合从四个维度进行排查（CPU、内存、磁盘、网络），例如 CPU 使用率峰值突然飚高、内存溢出 (泄露)、磁盘满了、网络流量异常、FullGC 等等问题。

​ 将线上问题分为两大类：系统异常、业务服务异常

系统异常

​ 常见系统异常： CPU 占用率过高、CPU 上下文切换频率次数较高、磁盘满了、磁盘 I/O 过于频繁、网络流量异常 (连接数过多)、系统可用内存长期处于较低值 (导致 oom killer)

​ 可以通过top(cpu)、free(内存)、df(磁盘)、dstat(网络流量)、pstack、vmstat、strace(底层系统调用) 等工具获取系统异常现象数据

​ 对系统和应用排查后未发现异常，则可考虑是否存在外部因素（调用第三方API接口、网络请求异常等）

业务异常

​ 常见的业务服务异常现象包括: PV 量过高、服务调用耗时异常、线程死锁、多线程并发问题、频繁进行 Full GC、异常安全攻击扫描等

问题定位&排查

​ 由外到内：排查第三方因素，排查系统异常因素、排查业务异常因素

Linux性能分析工具

（1）CPU指标监控

top：实时显示系统各个进程的资源占用情况，用于服务端性能分析

TOP命令显示了各个进程 CPU 使用情况 , 一般 CPU 使用率从高到低排序展示输出。其中 Load Average显示最近 1、5、15 分钟的系统平均负载，上图各值为0.11、0.07、0.06

一般会关注 CPU 使用率最高的进程，正常情况下就是应用主进程（不排查其他应用进程，此处以宝塔面板部署展示）。第七行以下：显示各进程的状态监控。

参数	说明
PID	进程 id
USER	进程所有者
PR	进程优先级
NI	nice 值。负值表示高优先级，正值表示低优先级
VIRT	进程使用的虚拟内存总量，单位 kb。VIRT=SWAP+RES
RES	进程使用的、未被换出的物理内存大小，单位 kb。RES=CODE+DATA<
SHR	共享内存大小，单位 kb
S	进程状态 。D= 不可中断的睡眠状态 R= 运行 S= 睡眠 T= 跟踪 / 停止 Z= 僵尸进程
%CPU	上次更新到现在的 CPU 时间占用百分比
%MEM	进程使用的物理内存百分比
TIME+	进程使用的 CPU 时间总计，单位 1/100 秒
COMMAND	进程名称

（2）内存监控指标

内存是排查线上问题的重要参考依据，内存问题很多时候是引起 CPU 使用率较高的间接因素

free：显示的当前内存的使用 ，-m ：M 字节来显示内容

参数	说明
total	内存总数: 3694M
used	已经使用的内存数: 2514M
free	空闲的内存数: 168M
shared	当前已经废弃不用 , 总是 0
buffers	Buffer 缓存内存数: 1010M

（3）磁盘监控指标

df：显示磁盘占用信息，df -h

# 查看指定路径的磁盘占用信息
du -m /path

（4）网络监控指标

dstat：集成vmstat、iostat、netstat 等工具能完成的任务

# 安装dstat指令
yum install dstat -y

# dstat指令使用
dstat -c  cpu 情况
    -d 磁盘读写
        -n 网络状况
        -l 显示系统负载
        -m 显示形同内存状况
        -p 显示系统进程信息
        -r 显示系统 IO 情况

（5）其他性能监控指标

vmstat：实时系统监控工具

​ vmstat 是 Virtual Meomory Statistics（虚拟内存统计）的缩写 , 是实时系统监控工具。该命令通过使用 knlist 子程序和 /dev/kmen 伪设备驱动器访问这些数据，输出信息直接打印在屏幕

# 查看io情况（参数1是采样时间间隔数单位秒；参数2采样次数）
vmstat 2 10 -t

strace：用来跟踪进程执行时的系统调用和所接收的信号

strace -cp tid
strace -T -p tid
    -T 显示每一调用所耗的时间 .
    -p pid  跟踪指定的进程 pid.
    -v 输出所有的系统调用 . 一些调用关于环境变量 , 状态 , 输入输出等调用由于使用频繁 , 默认不输出 .
    -V 输出 strace 的版本信息 .

JVM定位问题工具

​ 在 JDK 安装目录的 bin 目录下默认提供了很多有价值的命令行工具。每个小工具体积基本都比较小，因为这些工具只是 jdk\lib\tools.jar 的简单封装

​ 其中，定位排查问题时最为常用命令包括：jps（进程）、jmap（内存）、jstack（线程）、jinfo(参数) 等

• jps: 查询当前机器所有 JAVA 进程信息；
• jmap: 输出某个 java 进程内存情况 (如:产生那些对象及数量等)；
• jstack: 打印某个 Java 线程的线程栈信息；
• jinfo: 用于查看 jvm 的配置参数；

（1）jps：查询当前机器所有 JAVA 进程信息

​ 当系统上线出现故障或者发生问题的时候，通过jps可以快速定位对应的Java进程的进程ID

​ 也可借助linux提供的指令，通过关键字进行跟踪（ps -ef | grep tomcat）获取到对应的进程

ps -ef | grep tomcat
ps -ef | grep "8080"

（2）jmap：输出某个 java 进程内存情况 (如:产生那些对象及数量等)

​ jmap(Java Memory Map) ：可以输出所有内存中对象的工具 , 甚至可以将 VM 中的 heap, 以二进制输出成文本

jmap -heap pid   输出当前进程 JVM 堆新生代、老年代、持久代等请情况，GC 使用的算法等信息
jmap -histo:live {pid} | head -n 10  输出当前进程内存中所有对象包含的大小
jmap -dump:format=b,file=/usr/local/logs/gc/dump.hprof {pid} 以二进制输出档当前内存的堆情况，然后可以导入 MAT 等工具进行

可能是jdk版本和部署中应用到的jdk不一致导致：

（3）jstack：打印某个 Java 线程的线程栈信息

​ 当某个Java 进程CPU占用率高，想要定位到其中CPU占用率最高的线程，可以参考如下步骤

• 利用top命令查看占CPU最高的线程pid
• 占用率最高的线程ID，将其转化为16进制形式（java native线程以16进制形式输出）
• 利用jstack打印出java线程调用栈的信息

# 1.top查看cpu占用最高的java进程
top

# 2.将对应进程ID转化为16进制
printf '%x\n' 27101

# 3.利用jstack指令打印java线程调用栈信息
jstack [pid] | grep [16进制的pid]
jstack 27101 | grep '69dd'

原因是pid的启动用户不是当前用户，需要切换到启动用户下执行jstack即可。

可以通过如下命令来处理：

sudo -u $user

jstack pid

（4）jinfo：用于查看 jvm 的配置参数

# 查看某个 JVM 参数值
jinfo -flag ReservedCodeCacheSize 28461
jinfo -flag MaxPermSize 28461

（5）jstat：

jstat -gc pid
jstat -gcutil `pgrep -u admin java`

内存分析工具

（1）MAT

​ MAT(Memory Analyzer Tool)，一个基于 Eclipse 的内存分析工具，是一个快速、功能丰富的 JAVA heap 分析工具，它可以帮助我们查找内存泄漏和减少内存消耗。

​ 使用内存分析工具从众多的对象中进行分析，快速的计算出在内存中对象的占用大小，看看是谁阻止了垃圾收集器的回收工作，并可以通过报表直观的查看到可能造成这种结果的对象

日志分析工具

（1）GC日志分析

GC日志详细分析

​ Java 虚拟机 GC 日志是用于定位问题重要的日志信息，频繁的 GC 将导致应用吞吐量下降、响应时间增加，甚至导致服务不可用。

​ 在 java 应用的启动参数中增加 -XX:+PrintGCDetails 可以输出 GC 的详细日志，例外还可以增加其他的辅助参数，如-Xloggc 制定 GC 日志文件地址

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/usr/local/gc/gc.log -XX:+UseConcMarkSweepGC

​ 无论是 minor GC 或者是 Full GC, 我们主要关注 GC 回收实时耗时 , 如 real=0.02secs, 即 stop the world 时间，如果该时间过长，则严重影响应用性能

CMS GC日志分析

Concurrent Mark Sweep(CMS) 是老年代垃圾收集器 , 从名字 (Mark Sweep) 可以看出，CMS 收集器就是 “标记-清除” 算法实现的，分为六个步骤：

• 初始标记 (STW initial mark)；
• 并发标记 (Concurrent marking)；
• 并发预清理 (Concurrent precleaning)；
• 重新标记 (STW remark)；
• 并发清理 (Concurrent sweeping)；
• 并发重置 (Concurrent reset)。

其中初始标记 (STW initial mark) 和 重新标记 (STW remark) 需要”Stop the World”。

初始标记 ：在这个阶段，需要虚拟机停顿正在执行的任务，官方的叫法 STW(Stop The Word)。这个过程从垃圾回收的 “ 根对象 “ 开始，只扫描到能够和 “ 根对象 “ 直接关联的对象，并作标记，所以这个过程虽然暂停了整个 JVM，但是很快就完成了。

并发标记 ：这个阶段紧随初始标记阶段，在初始标记的基础上继续向下追溯标记。并发标记阶段，应用程序的线程和并发标记的线程并发执行，所以用户不会感受到停顿。

并发预清理 ：并发预清理阶段仍然是并发的。在该阶段，虚拟机查找在执行并发标记阶段新进入老年代的对象 (可能会有一些对象从新生代晋升到老年代， 或者有一些对象被分配到老年代)。

通过重新扫描，减少下一个阶段 “ 重新标记 “ 的工作，因为下一个阶段会 Stop The World。

重新标记 ：这个阶段会暂停虚拟机，收集器线程扫描在 CMS 堆中剩余的对象。扫描从 “ 跟对象 “ 开始向下追溯，并处理对象关联。

并发清理 ：清理垃圾对象，这个阶段收集器线程和应用程序线程并发执行。

并发重置 ：这个阶段，重置 CMS 收集器的数据结构，等待下一次垃圾回收。

cms 使得在整个收集的过程中只是很短的暂停应用的执行 , 可通过在 JVM 参数中设置 -XX:UseConcMarkSweepGC 来使用此收集器 , 不过此收集器仅用于 old 和 Perm(永生) 的对象收集。

CMS 减少了 stop the world 的次数，不可避免地让整体 GC 的时间拉长了。

Full GC 的次数说的是 stop the world 的次数，所以一次 CMS 至少会让 Full GC 的次数 +2，因为 CMS Initial mark 和 remark 都会 stop the world，记做 2 次。而 CMS 可能失败再引发一次 Full GC

如果你已掌握 CMS 的垃圾收集过程，那么上面的 GC 日志你应该很容易就能看的懂，这里我就不详细展开解释说明了。

此外 CMS 进行垃圾回收时也有可能会发生失败的情况。

异常情况有：

1）伴随 prommotion failed, 然后 Full GC：

[prommotion failed：存活区内存不足，对象进入老年代，而此时老年代也仍然没有内存容纳对象，将导致一次 Full GC]

2）伴随 concurrent mode failed，然后 Full GC：

[concurrent mode failed：CMS 回收速度慢，CMS 完成前，老年代已被占满，将导致一次 Full GC]

3）频繁 CMS GC：

[内存吃紧，老年代长时间处于较满的状态]

（2）业务日志分析

​ 业务日志除了关注系统异常与业务异常之外，还要关注服务执行耗时情况，耗时过长的服务调用如果没有熔断等机制，很容易导致应用性能下降或服务不可用，服务不可用很容易导致雪崩

​ 排查业务调用响应时间长的接口

​ 日常业务日志可以借助log4j或者其他日志接口统一日志输出格式规范