Java应用线上问题排查工具整理

关于线上问题

Java应用的线上问题,总结起来大概分为几类:CPU占用高,内存溢出,执行结果不对。

CPU占用高

引起CPU占用高的原因可能有多种,比如:

  • 代码进入死循环
  • 并发请求量大
  • 频繁Full GC
  • 打印日志太过于频繁

内存溢出

导致内存溢出的原因可能是:

  • 分配的Java堆空间不够,可以通过启动参数-Xms -Xmx指定
  • 程序在执行过程中创建了过多的对象实例,又无法及时回收
  • JVM使用的GC回收器不合适,通过GC调优进行优化

执行结果不对

导致执行结果不对的原因:

  • 代码逻辑不正确,这个在发布之前通过单元测试和代码Review可以提前规避
  • 数据不正确,这个需要通过日志排查,必要的时候需要通过在线上环境进行定位

诊断工具

不论何种线上问题,在发生时我们都希望能有工具进行排查和定位,这些工具可能是启动参数,日志,命令行(脚本),独立的程序等。

日志

日志是排查线上问题的第一首选,足够的日志输出可以让我们进行数据分析和推断,这里的日志包括但不限于如下类型:

  • 应用程序日志
  • 框架日志
  • GC日志

应用程序日志

在程序中合理地打印相关日志,对于排查和诊断问题非常有用。在Java中最常使用的日志框架组合是:slf4j + logback,参考:细说java平台日志组件。在程序中打印日志时,要注意一个“度”,即:要控制好日志信息的数量,以及日志级别。比如,DEBUG级别的日志在开发测试阶段时非常有利于排查问题,但是到线上环境的时候需要将日志级别设置为INFO,否则过多的日志打印也会影响性能。

框架日志

框架日志也是属于应用程序日志范畴,需要注意的是:可能需要在日志框架中进行合理的配置后才能输出,比如指定相应包名的日志级别等等。

GC日志

GC日志对于排查线上应用是否出现了内存空间不足的问题非常有用,而且当线上环境出现CPU占用高的时候也需要排查是否出现了频繁的Full GC,此时从GC日志中可以非常直观地看到。Java应用的GC日志打印通过在启动参数中指定,如:-Xloggc:/tmp/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=2M,各参数项含义如下:

  • -Xloggc:/tmp/gc.log 日志文件的输出路径
  • -XX:+PrintGC 输出GC日志
  • -XX:+PrintGCDetails 输出GC的详细日志
  • -XX:+PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
  • -XX:+PrintGCDateStamps 输出GC的时间戳(以日期的形式,如2013-05-04T21:53:59.234+0800
  • -XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
  • -XX:NumberOfGCLogFiles=10 控制GC日志文件个数
  • -XX:GCLogFileSize=2M 设置单个GC日志文件大小

当然,GC的概要情况还可以直接使用JDK自带的jstat命令进行查看。
jstat命令用法:

$ jstat -help
Usage: jstat -help|-options
       jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]

Definitions:
  <option>      An option reported by the -options option
  <vmid>        Virtual Machine Identifier. A vmid takes the following form:
                     <lvmid>[@<hostname>[:<port>]]
                Where <lvmid> is the local vm identifier for the target
                Java virtual machine, typically a process id; <hostname> is
                the name of the host running the target Java virtual machine;
                and <port> is the port number for the rmiregistry on the
                target host. See the jvmstat documentation for a more complete
                description of the Virtual Machine Identifier.
  <lines>       Number of samples between header lines.
  <interval>    Sampling interval. The following forms are allowed:
                    <n>["ms"|"s"]
                Where <n> is an integer and the suffix specifies the units as
                milliseconds("ms") or seconds("s"). The default units are "ms".
  <count>       Number of samples to take before terminating.
  -J<flag>      Pass <flag> directly to the runtime system.

如下示例:

# 查看指定进程的GC概要信息,自动刷新频率为1000ms
$ jstat -gcutil 进程ID 1000

线程堆栈

线程堆栈信息对于分析CPU占用高的问题非常有帮助,由于线程堆栈都是动态变化的,所以通常都是在需要排查问题的再查看。打印线程堆栈日志有2种方式:

  • JDK自带的jstack命令
  • Arthas工具的thread命令

jstack命令用法:

$ jstack -h
Usage:
    jstack [-l] <pid>
        (to connect to running process)
    jstack -F [-m] [-l] <pid>
        (to connect to a hung process)
    jstack [-m] [-l] <executable> <core>
        (to connect to a core file)
    jstack [-m] [-l] [server_id@]<remote server IP or hostname>
        (to connect to a remote debug server)

Options:
    -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)
    -m  to print both java and native frames (mixed mode)
    -l  long listing. Prints additional information about locks
    -h or -help to print this help message

示例:

# 将指定Java进程的线程堆栈日志输出到文件中
$ jstack 进程ID > stack.tdump

# 当Java进程夯住没有响应时,需要使用-F选项参数
$ jstack -F 进程ID > stack.tdump

针对线上环境,如果希望能快速查看CPU占用高的线程堆栈,可以将相关命令写在一个shell脚本中,直接执行脚本即可,如下:

#!/bin/bash
# Desc: 查看Java进程CPU使用率高的线程堆栈信息
# File: show_java_process_thread_stack.sh

echo "Show java process thread stack"
pid=$1
if [ ! "$pid" ]; then
	echo "Usage: sh $0 pid"
	echo "  e.g: sh $0 1234"
	echo ""
	exit 1
fi

top -H -p "$pid"|head -20
echo ""

top_thread_id=`top -H -p $pid|head -8|awk '/java/{print $2}'`
#echo "top cpu thread: $top_thread_id"

thread_id_hex=`printf "%x" "$top_thread_id"`
#echo "$thread_id_hex"
jstack "$pid"|grep "$thread_id_hex" -A 100 > jstack_tmp
cat jstack_tmp
rm -rf jstack_tmp

#echo "Done."

如果线上环境有Arthas诊断工具,那么使用其thread命令会更加方便,如下示例:

# 当没有参数时,显示第一页线程的信息
# 默认按照CPU增量时间降序排列,只显示第一页数据
$ thread

# 展示当前最忙的前N个线程并打印堆栈
$ thread -n 3

# 显示指定线程的运行堆栈
$ thread 进程ID

# 找出当前阻塞其他线程的线程
# 只支持找出synchronized关键字阻塞住的线程
$ thread -b

# 指定采样时间间隔
$ thread -i 1000 # 统计最近1000ms内的线程CPU时间
$ thread -n 3 -i 1000 # 列出1000ms内最忙的3个线程栈

堆内存dump

前面通过GC日志可以知道进程的GC情况,当频繁出现Full GC的时候,有2种可能:其一,分配的堆内存空间不够;其二,出现了无法进行垃圾回收的大对象。不论是何种情况,此时都需要将堆内存信息dump下来进行分析和定位。有2个工具可以使用:

  • JDK自带的jmap命令
  • Arthas工具的heapdump命令
  • 通过启动参数设置当出现OutOfMemoryError错误时自动生成dump文件

jmap命令用法:

$ jmap -help
Usage:
    jmap [option] <pid>
        (to connect to running process)
    jmap [option] <executable <core>
        (to connect to a core file)
    jmap [option] [server_id@]<remote server IP or hostname>
        (to connect to remote debug server)

where <option> is one of:
    <none>               to print same info as Solaris pmap
    -heap                to print java heap summary
    -histo[:live]        to print histogram of java object heap; if the "live"
                         suboption is specified, only count live objects
    -clstats             to print class loader statistics
    -finalizerinfo       to print information on objects awaiting finalization
    -dump:<dump-options> to dump java heap in hprof binary format
                         dump-options:
                           live         dump only live objects; if not specified,
                                        all objects in the heap are dumped.
                           format=b     binary format
                           file=<file>  dump heap to <file>
                         Example: jmap -dump:live,format=b,file=heap.bin <pid>
    -F                   force. Use with -dump:<dump-options> <pid> or -histo
                         to force a heap dump or histogram when <pid> does not
                         respond. The "live" suboption is not supported
                         in this mode.
    -h | -help           to print this help message
    -J<flag>             to pass <flag> directly to the runtime system

如下示例:

# 导出指定进程的堆dump文件
$ jmap -dump:format=b,file=/tmp/heapdump.hprof 进程ID

# 当Java进程夯住没有响应时,需要使用-F选项参数
$ jmap -F -dump:format=b,file=/tmp/heapdump.hprof 进程ID

如果线上环境有Arthas诊断工具,那么使用其heapdump命令就可以非常方便到导出堆内存dump文件,如下示例:

# dump到指定文件
$ heapdump /tmp/dump.hprof

# 只dump live对象
$ heapdump --live /tmp/dump.hprof

# dump到临时文件
$ heapdump

还可以通过启动参数设置当出现OutOfMemoryError错误时自动生成堆内存dump文件:-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/headpdump.hprof

然后使用MAT工具对堆内存dump文件进行分析。

最后总结

关于Java应用线上问题的排查工具,总结起来:

  • 启动参数
  • JDK自带的命令行工具,如:jstack,jstat,jmap,jps
  • Arthas诊断工具中的命令
  • 应用程序日志
  • MAT:用于分析堆内存dump文件

一个完整的Java应用启动参数示例如下:

# 指定了最小堆和最大堆的大小
# 设置生成gc日志文件
# 设置在出现OutOfMemoryError错误自动生成堆内存dump文件
$ java -Xms1024m -Xmx1024m -Xloggc:/tmp/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=2M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/headpdump.hprof -jar test.jar
# 当然,如果进行了JVM优化,还需要包含其他一些参数,比如:指定GC垃圾回收器等

充分利用好这些工具,能够大大提高线上故障的排查效率。

另外,对于一些性能问题的分析,还需要如链路跟踪服务监控这样的系统进行追踪,才能更好地分析出在哪个环节耗时最多。

如果是部署在K8S环境的Docker容器中,为了方便地将堆内存dump文件拷贝出来,可能还需要一些外部的存储系统进行辅助,如:OSS。这样就可以很方便地在Docker容器中将相应文件上传到OSS系统,然后拿到外部进行分析。

posted @ 2024-06-15 23:45  nuccch  阅读(122)  评论(0编辑  收藏  举报