【语言学习】JAVA问题排查 - hippowc/hippowc.github.io GitHub Wiki

java常见问题

NoSuchMethodException

类似问题还有:ClassNotFoundException/NoClassDefFoundError/ClassCastException

一般出现的原因:

  • jar包冲突
  • classLoader机制

排查方法:

在java应用启动时增加vm参数:-XX:+TraceClassLoading。这个参数的作用是监控类的加载,这样可以在启动时看到这个类是加载的哪个地方的。

这个是比较高级的排查方法。其实一般不需要这么复杂。一般遇到类似的错误,我们会通过ide去查询下这个project中有多少个相同类名的文件,然后找到删掉就可以了。

cpu us高

us指的是user space,即,用户态使用的cpu时间比,原因一般有:

  • CMS GC/Full GC频繁 : 查看gc log,或jstat –gcutil [pid] 1000 10
  • 代码中出现非常耗CPU的操作 : top –H + jstack,做pid到nid的16进制转化(printf '0x%x')
  • 整体代码的消耗 : top –H看到每个线程消耗都差不多,而且不断变化; perf –top

cpu sy高

系统态使用的cpu时间比,原因一般是:

  • 锁竞争激烈
  • 线程主动切换频繁

这种情况一般使用 jstack 查看锁状况;或者查看下是否有主动线程切换

cpu io wait高

出现这个问题原因,一般是io读写操作频繁。

解决方案:使用cache,同步写转异步写,最终可以上昂贵的硬件。

java.lang.OutOfMemoryError

  • GC overhead limit exceeded
  • Java Heap Space
  • Unable to create new native thread
  • PermGen Space
  • Direct buffer memory
  • Map failed

应用没响应

出现的原因一般是cpu或者memory资源被占满,具体来说:

  • 死锁
  • 线程池线程耗光

排查方法

jstack -l 查看线程堆栈信息

解决方法:

  • 如果是死锁就需要修改代码解决死锁。
  • 线程池耗光,可以加大线程池或者减少超时时间

案例

大对象高GC案例

现象:cpu load一直居高不下

使用top命令发现,cpu占比百分之一百朝上

使用ps -ef | grep pid 查看是这个进程是做什么的

是java进程,使用 top -Hp pid 查看具体哪个线程有问题,找到具体的高cpu线程,转换为16进制(jstatck中java线程是16进制表示),使用printf "%x" pid

使用jstack 主线程pid,然后根据上面转换为16进制的pid,找到这个线程是做什么的

发现是GC线程,也就是说程序gc很高

使用jmap -heap 164065 查看堆内存情况。发现年轻代和老年代都被占满了,所以jvm频繁进行full gc,而full gc是很耗cpu的

通过jstat -GC pid,查看一下GC的频率

查看具体是什么类这么占空间,可以dump堆 jmap -dump:format=b,file=taskDump.bin 生产dump文件

使用相关工具分析,譬如zprofiler,发现了有几个大对象,需要优化掉

其中有几个概念:

  • shallow heap:浅层堆,其实就是这个对象实际占用的堆大小。
  • retained heap: 不能按照 shallow(浅) 和 deep(深)的层次来理解这个retained heap,其实最简单的理解就是,如果这个对象被删除了(GC回收掉),能节省出多少内存,这个值就是所谓的retained heap。

局部线程池案例

现象:应用提供的hsf调用超时

应用本身只提供了一个日志记录的功能,不应该有这么大的开销。

使用top命令,发现cpu占用100%,内存占用70%。一般来说应用相应很慢,都是资源不够用导致的,或者cpu满了,或者内存满了,具体的话可能是由于死锁或者线程池满。

将堆栈dump下来之后,发现有很多名字类似的线程"collect-data-1",正常来讲线程池创建的线程名称是递增的,如果有线程名称重复,则很大概率是由于多个线程池创建的线程。

使用cat /proc/{pid}/status 查看当前java进程有多少个线程,发现有3W个,正常应用几百个线程,说明很有可能线程池运行完任务后,没有shutdown。如果不关闭的话,运行后的线程会作为core线程保存着线程池中,且WAITING状态,这个线程对象是不会被回收的。然后去代码中找到这个部分代码修改掉。

总结:局部线程池问题是常见的初级的多线程使用不当,最佳实践是构造一个单例线程池,所有任务都公用一个,而不是每个请求都新建一个线程池,开销比较大。如果必须要在局部使用线程池跑多线程任务,那么一定要记得完成后shutdown。否则最终耗尽内存和线程

OOM-killer案例

现象:服务器并发连接陡增后,java线程消失

  • 使用 cat /proc/{pid}/status 查看java线程数量,已经爆满,当时应用单机线程上线 600,多余请求被拒绝
  • jvm内存占用正常,cpu load也正常
  • 机器内存占用飙升
  • 同时看到单机的established 连接数飙升,7w左右

分析:

  • 连接数飙升,API调用失败,客户端降级,绕过代理直接访问机器
  • 大量连接数和内存的关系?通过ab线下压力测试,发现使用http请求正常,使用https请求挂了
  • ps -ef | grep nginx 发现nginx的内存占用陡增
  • 当机器内存资源不足时,触发oom-killer 杀死内存占用最大的java进程

接口性能案例

现象:某一个接口调用时间过长,甚至超时

分析:

  • 使用工具查看整个链路的调用时长
  • 使用鹰眼查看整个服务链路调用时长问题,但是粒度不够细
  • 使用arthus查看入口函数调用时长问题,一步步细化,查看调用时长问题,最终可以排查出应用内那个接口有问题

Java问题排查工具箱

日志相关工具

  • tail
  • find
  • fgrep
  • awk

cpu相关工具

  • top(-H) top可以实时查看cpu指标,-H可以查看具体线程
  • sar 可以用来查看历史指标数据,除了cpu,其他的像内存,磁盘,网络等各种指标都可以查看
  • jstack 可以用来查看java的线程在干什么,通常对于应用无反应或者比较慢这种场景很有帮助,默认可以查看Java栈,jstack -m可以查看java栈和native栈
  • perf 一些简单的CPU消耗的问题靠着top -H + jstack通常能解决,复杂的话就需要借助perf
  • cat /proc/interrupts 网卡的多队列以及均衡

内存相关工具

  • jstat jstat -gcutil或-gc等等有助于实时看gc的状况
  • jmap 在需要dump内存看看内存里都是什么的时候,jmap -dump可以帮助你;在需要强制执行fgc的时候jmap -histo:live可以帮助你(显然,不要随便执行)
  • gcore
  • mat 内存分析工具,和zprofiler类似
  • btrace 少数的问题可以mat后直接看出,而多数会需要再用btrace去动态跟踪,btrace绝对是Java中的超级神器,举个简单例子,如果要你去查下一个运行的Java应用,哪里在创建一个数组大小>1000的ArrayList
  • gperf

除了上面的工具外,同样内存信息的记录也非常重要,就如日志一样,所以像GC日志是一定要打开的,确保在出问题后可以翻查GC日志来对照是否GC有问题,所以像-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc: 这样的参数必须是启动参数的标配。

ClassLoader相关工具

不碰到ClassLoader问题那基本是不可能的,在排查此类问题时,最好办的还是-XX:+TraceClassLoading,或者如果知道是什么类的话,我的建议就是把所有会装载的lib目录里的jar用jar -tvf *.jar这样的方式来直接查看冲突的class,再不行的话就要呼唤btrace神器去跟踪Classloader.defineClass之类的了。

其他工具

  • jinfo Java有N多的启动参数,N多的默认值,而任何文档都不一定准确,只有用jinfo -flags看到的才靠谱
  • dmesg java进程突然不见了,可以试试dmesg先看看
  • systemtap 有些问题排查到java层面是不够的,当需要trace更底层的os层面的函数调用的时候,systemtap神器就可以派上用场了
  • gdb 更高级的玩家们,拿着core dump可以用gdb来排查更诡异的一些问题。
  • Arthas 阿里开源工具,https://github.com/alibaba/arthas 这个工具很牛逼,可以看下实现代码