Java排查问题随笔

　　常言道：“好记性不如烂笔头”，确实很有道理。在日常工作中，偶尔处理下线上问题还是很常见的，经常出现的情况就是忘记一些常用命令（套路）的用法了，因此整理下来非常用必要，以便关键时刻可以节省到处搜索的时间。

常用Linux命令

　　1. top命令，直观查看机器资源使用情况。

(1)top -Hp PID 查看指定进程具体线程、内存使用情况
(2)输入top后，按P以CPU 占用率大小的顺序排列进程列表
(3)输入top后，按M以内存占用率大小的顺序排列进程列表

　　2. free命令，这个命令估计大家也肯定经常用, 但是命令结果每行每列具体含义，经常容易忘记。

1）先看第一行 　　
　　　　　　   total       used        free      shared      buffers   cached
Mem:          7804       7643        161        153        333       2658
机器总的总内存(total)为7804MB、其中使用了(used)7643MB、还剩下(free)161MB未使用，这几个指标应该是最好理解的。
另外某部分内存是可以共享的，比如程序代码片段可以被多个进程共享，这部分就是shared指标的含义了，也就是说有153MB内存被用于做共享内存了。
重点说下buffers和cached两个指标，这2个指标所占用的内存都是Linux为了提高访问性能而用来做高速缓存的，查了下资料有说cache是用于文件系统缓存，buffer是用于块设备缓存，还有的书籍说内核2.2以后cache和buffer整合成了一个"通用数据块层"，想要深究只能自行查询更官方的文档了。简而言之，这部分内存是Linux内核自行维护的，不需要我们关心，正因为有了这些高速缓存，linux才不需要频繁IO操作，性能才得以提高。

2)第二行

　　-/+ buffers/cache: 4651 3153

　　这行的含义经常容易搞混。其实它想表达的是如果系统禁用buffer和cache高速缓存，那么系统实际就只使用了4651MB内存，还剩余3153MB内存。换个说法，就是第一行的

used = 实际使用的内存 + buggers/cache的内存, 而第一行的free= total - used。

　3)第三行

　　Swap: 30517 231 30286

　　这行的数据表示交换空间的总量、使用量、和剩余量。由于交换空间是在内存不足的情况下，使用磁盘当内存用，所以这行如果出现了使用量比较多的情况，那就真的事内存不够，要好好检查下是不是有什么内存泄漏了。

　4）总结下

　　实际上判断内存使用情况，直接看第二行就行了，这行是系统程序实际使用的内存情况，而对于buffer和cache完全是由内核去控制的，应该是不建议我们去干预的。另外如果第三行数据有异常，就该认真排查了。

查看JVM堆栈命令

　　1. jmap

1）jmap -dump:file=hprof-jvm.bin -F PID 转存jvm堆栈信息文件
获取到堆栈信息的二进制文件后，可以使用Eclipse的MAT去分析是否存在异常情况，MAT这个东西确实好用，而且能帮我们自动分析去一些异常，比如内存泄漏什么的。附上下载地址 http://www.eclipse.org/mat/。

2）jmap -histo PID

获取每个class的实例数目,内存占用,类全名信息. VM的内部类名字开头会加上前缀”*”. 如果live子参数(-histo:live )加上后,只统计活的对象数量.

　　2.jstack -l PID >> jstack.data。打印活动线程信息

查看GC日志

　　目前接触项目都是CMS比较多(不知道是不是我们公司比较土~~)，GC日志打印内容非常多，第一次看的话确实是懵。了解 CMS 垃圾回收日志，里面有比较清晰说明。这里我只摘录查阅资料后几点个作为笔记。

1)我们的CMS full gc时，经常会看到如下信息：CMS: abort preclean due to time， 这个问题有篇文章讲的很透彻：https://blogs.oracle.com/jonthecollector/entry/did_you_know。主要的意思是：preclean是为了加速下一级的remark过程，因为remark过程是STW的。preclean过程中为了更好的使用parallel，它会等待一次小gc（默认等待5s），如果5s内小gc没来，就会强制开始STW remark过程，并打印信息abort preclean due to time。就是说，出现这个log实际上关系不大，除非我们发现remark过程耗时过久。

2)13901.282: [GC 13901.283: [ParNew: 8766574K->400883K(9216000K), 1.9300940 secs] 10239467K->1917256K(11578944K), 1.9309390 secs] [Times: user=13.68 sys=0.07, real=1.93 secs]
这段ParNew GC日志最后有三个时间[Times: user=13.68 sys=0.07, real=1.93 secs]含义是指user是用户态花费的时间，sys是内核态花费的时间，而real是实际花费的时间，user+sys是CPU时间，每个CPU core单独计算，所以这个时间可能会是real的好几倍。