关于线上问题
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.
如下示例:
代码语言:javascript复制# 查看指定进程的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
示例:
代码语言:javascript复制# 将指定Java进程的线程堆栈日志输出到文件中
$ jstack 进程ID > stack.tdump
# 当Java进程夯住没有响应时,需要使用-F选项参数
$ jstack -F 进程ID > stack.tdump
针对线上环境,如果希望能快速查看CPU占用高的线程堆栈,可以将相关命令写在一个shell脚本中,直接执行脚本即可,如下:
代码语言:javascript复制#!/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
如下示例:
代码语言:javascript复制# 导出指定进程的堆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应用启动参数示例如下:
代码语言:javascript复制# 指定了最小堆和最大堆的大小
# 设置生成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系统,然后拿到外部进行分析。