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

标签：Java thread dump 排查 XX GC 线上线程日志

关于线上问题

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系统，然后拿到外部进行分析。

标签：Java,thread,dump,排查,XX,GC,线上,线程,日志
From： https://www.cnblogs.com/nuccch/p/18250049