Java 问题 定位

遇到问题第一反应,看日志,重现。

  1. 看日志,定位是传参的问题,还是程序逻辑,还是代码里内存未释放。

  2. 重现问题

  3. 分析问题
    用 JMX JMC jvisualvm 查看Java服务在运行过程中的内存、GC、线程等信息。
    VisualVM是Sun的一个OpenJDK项目,它是集成了多个JDK命令工具的一个可视化工具,它主要用来监控JVM的运行情况,可以用它来查看和浏览Heap Dump、Thread Dump、内存对象实例情况、GC执行情况、CPU消耗以及类的装载情况,也可以使用它来创建必要信息的日志。

    也可以使用jstat命令来堆Java堆内存的使用情况进行统计 pid 3031
    jstat -gcutil 3031 1000 10

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    [wkq@VM_77_25_centos ~]$ jstat -gcutil 3031 1000 10 
    S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
    0.00 100.00 27.27 78.98 97.75 97.20 155 1.642 0 0.000 1.642
YGC: 从启动到采样时Young Generation GC的次数
YGCT: 从启动到采样时Young Generation GC所用的时间 (s).
FGC: 从启动到采样时Old Generation GC的次数.
FGCT: 从启动到采样时Old Generation GC所用的时间 (s).
GCT: 从启动到采样时GC所用的总时间 (s).

查看CPU 内存使用情况

使用 top 命令,查看CPU 内存使用情况

1
2
3
4
5
6
7
8
9
10
11
12
[wkq@VM_77_25_centos ~]$ top
top - 16:02:17 up 69 days, 23:08, 1 user, load average: 0.03, 0.03, 0.05
Tasks: 68 total, 2 running, 66 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.3 us, 0.3 sy, 0.0 ni, 99.0 id, 0.3 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 1883844 total, 75024 free, 430228 used, 1378592 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 1266684 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3031 wkq 20 0 2692228 354060 4156 S 0.3 18.8 477:30.26 java
16414 root 20 0 612232 13740 2380 S 0.3 0.7 21:40.11 barad_agent
1 root 20 0 41020 2900 1816 S 0.0 0.2 4:49.45 systemd
......

load 值

load average 代表1分钟、5分钟、15分钟的系统平均负载,从这三个数字,可以判断系统负荷是大还是小。
当CPU完全空闲的时候,平均负荷为0;当CPU工作量饱和的时候,平均负荷为1。
因此 load average 这三个数值越低,代表系统负荷越小。

单核CPU load值0.7比较合理
8核CPU load值 7 - 8 比较合理

如果电脑里只有一个CPU,把CPU看成一条单行桥,桥上只有一个车道,所有的车都必须从这个桥上通过。那么
系统负荷为0,代表桥上一辆车也没有
系统负荷0.5,意味着桥上一半路段上有车
系统负荷1,意味着桥上道路已经被车占满
系统负荷1.7,代表着在桥上车子已经满了(100%),同时还有70%的车子在等待从桥上通过

获取占用CPU最高的线程id

top -p 12309 -H
-p用于指定进程,-H用于获取每个线程的信息。从top输出的内容,可以看到有四个线程占用了非常高的CPU:
从top输出的内容,可以看到有四个线程占用了非常高的CPU:

jstack是java虚拟机自带的一种堆栈跟踪工具,用于打印出给定的java进程ID或core file或远程调试服务的Java堆栈信息。使用下面命令,将java进程的堆栈信息打印到文件中
jstack -l 12309 > stack.log

是哪些对象占用了内存

用VisualVM来生成headdump文件。
在机器上使用jmap命令来生成head dump文件。
jmap -dump:live,format=b,file=headInfo.hprof 12309

live这个参数表示我们需要抓取的是目前在生命周期内的内存对象,也就是说GC收不走的对象,在这种场景下,我们需要的就是这些内存的信息。生成了hprof文件后,可以拉回到本地,使用VisualVM来打开它进行分析。

使用下面的命令,来查看占用内存最多的类型:
jmap -histo 12309 > heap.log

能否对堆内对象进行查询

如果能够分析出相似度高的字符串,那么有比较大的可能是这些字符串存在泄漏,从而可以缩小问题代码的范围。确实是有这么一种工具来对堆内的对象进行分析,也就是OQL(Object Query Language),在VisualVM中可以对headdump文件执行对象查询,下面是一个示例,查找包含内容最多的List:

select map(top(heap.objects('java.util.ArrayList'), 'rhs.size - lhs.size', 5),"toHtml(it)+'='+it.size")

References

[1] 从一次线上故障思考 Java 问题定位思路
[2] 从一次线上故障思考 Java 问题定位思路