注意:
由于本周大家的笔记过于精彩,因此就出个合集好了,分享一下优秀的笔记。互相学习。
服务器问题排查手册之高 CPU 占用
该手册用于排查 Java 项目的 CPU 性能问题(top us 值过高),根据线程 id 逐步找到并打印出问题线程栈,从而确定导致性能问题的方法调用。 一个应用占用 CPU 很高,除了确实是计算密集型应用之外,也有可能是出现了死循环。 解决思路/方案
下面我们出现的一个实际故障为例,介绍怎么定位和解决这类问题。
根据 top 命令,发现测试环境 PID 为 5989 的 Java 进程占用 CPU 高达 100%, 疑似故障。但是,怎么定位到具体线程或者代码呢?
image-20211230174244190
首先显示线程列表:
ps -mp pid -o THREAD,tid,time
image-20211230174320441
找到了耗时最高的线程 6048,占用 CPU 时间已经两个小时了
其次将需要的线程 ID 转换为 16 进制格式:
printf "%x\n" tid
image-20211230174346931
最后打印线程的堆栈信息
jstack pid | grep tid -A 30
image-20211230174413323
找到了出现问题的代码堆栈信息, 至于具体怎么修改就看具体业务逻辑,这里不做展开讨论.
总结下排查 CPU 故障的方法和技巧有哪些:
CPU
使用率排序最后, 实际工程中会要多次这样操作以确定问题,上面过程太繁琐了, 分享一个脚本给大家:
该脚本用于快速排查 Java 的 CPU 性能问题(top us 值过高),自动查出运行的 Java 进程中消耗 CPU 多的线程,并打印出其线程栈,从而确定导致性能问题的方法调用。
#!/bin/bash
# @Function
# Find out the highest cpu consumed threads of java, and print the stack of these threads.
#
# @Usage
# $ ./show-busy-java-threads.sh
#
# @author sean
readonly PROG=`basename $0`
readonly -a COMMAND_LINE=("$0" "$@")
usage() {
cat <<EOF
Usage: ${PROG} [OPTION]...
Find out the highest cpu consumed threads of java, and print the stack of these threads.
Example: ${PROG} -c 10
Options:
-p, --pid find out the highest cpu consumed threads from the specifed java process,
default from all java process.
-c, --count set the thread count to show, default is 5
-h, --help display this help and exit
EOF
exit $1
}
readonly ARGS=`getopt -n "$PROG" -a -o c:p:h -l count:,pid:,help -- "$@"`
[ $? -ne 0 ] && usage 1
eval set -- "${ARGS}"
while true; do
case "$1" in
-c|--count)
count="$2"
shift 2
;;
-p|--pid)
pid="$2"
shift 2
;;
-h|--help)
usage
;;
--)
shift
break
;;
esac
done
count=${count:-5}
redEcho() {
[ -c /dev/stdout ] && {
# if stdout is console, turn on color output.
echo -ne "\033[1;31m"
echo -n "$@"
echo -e "\033[0m"
} || echo "$@"
}
yellowEcho() {
[ -c /dev/stdout ] && {
# if stdout is console, turn on color output.
echo -ne "\033[1;33m"
echo -n "$@"
echo -e "\033[0m"
} || echo "$@"
}
blueEcho() {
[ -c /dev/stdout ] && {
# if stdout is console, turn on color output.
echo -ne "\033[1;36m"
echo -n "$@"
echo -e "\033[0m"
} || echo "$@"
}
# Check the existence of jstack command!
if ! which jstack &> /dev/null; then
[ -z "$JAVA_HOME" ] && {
redEcho "Error: jstack not found on PATH!"
exit 1
}
! [ -f "$JAVA_HOME/bin/jstack" ] && {
redEcho "Error: jstack not found on PATH and $JAVA_HOME/bin/jstack file does NOT exists!"
exit 1
}
! [ -x "$JAVA_HOME/bin/jstack" ] && {
redEcho "Error: jstack not found on PATH and $JAVA_HOME/bin/jstack is NOT executalbe!"
exit 1
}
export PATH="$JAVA_HOME/bin:$PATH"
fi
readonly uuid=`date +%s`_${RANDOM}_$$
cleanupWhenExit() {
rm /tmp/${uuid}_* &> /dev/null
}
trap "cleanupWhenExit" EXIT
printStackOfThreads() {
local line
local count=1
while IFS=" " read -a line ; do
local pid=${line[0]}
local threadId=${line[1]}
local threadId0x="0x`printf %x ${threadId}`"
local user=${line[2]}
local pcpu=${line[4]}
local jstackFile=/tmp/${uuid}_${pid}
[ ! -f "${jstackFile}" ] && {
{
if [ "${user}" == "${USER}" ]; then
jstack ${pid} > ${jstackFile}
else
if [ $UID == 0 ]; then
sudo -u ${user} jstack ${pid} > ${jstackFile}
else
redEcho "[$((count++))] Fail to jstack Busy(${pcpu}%) thread(${threadId}/${threadId0x}) stack of java process(${pid}) under user(${user})."
redEcho "User of java process($user) is not current user($USER), need sudo to run again:"
yellowEcho " sudo ${COMMAND_LINE[@]}"
echo
continue
fi
fi
} || {
redEcho "[$((count++))] Fail to jstack Busy(${pcpu}%) thread(${threadId}/${threadId0x}) stack of java process(${pid}) under user(${user})."
echo
rm ${jstackFile}
continue
}
}
blueEcho "[$((count++))] Busy(${pcpu}%) thread(${threadId}/${threadId0x}) stack of java process(${pid}) under user(${user}):"
sed "/nid=${threadId0x} /,/^$/p" -n ${jstackFile}
done
}
ps -Leo pid,lwp,user,comm,pcpu --no-headers | {
[ -z "${pid}" ] &&
awk '$4=="java"{print $0}' ||
awk -v "pid=${pid}" '$1==pid,$4=="java"{print $0}'
} | sort -k5 -r -n | head --lines "${count}" | printStackOfThreads
用法
show-busy-java-threads.sh
# 从 所有的 Java 进程中找出最消耗 CPU 的线程(默认5个),打印出其线程栈。
show-busy-java-threads.sh -c <要显示的线程栈数>
show-busy-java-threads.sh -c <要显示的线程栈数> -p <指定的Java Process>
##############################
# 注意:
##############################
# 如果 Java 进程的用户 与 执行脚本的当前用户 不同,则 jstack 不了这个 Java 进程。
# 为了能切换到 Java 进程的用户,需要加 sudo 来执行,即可以解决:
sudo show-busy-java-threads.sh
示例
$ show-busy-java-threads.sh
[1] Busy(57.0%) thread(23355/0x5b3b) stack of java process(23269) under user(admin):
"pool-1-thread-1" prio=10 tid=0x000000005b5c5000 nid=0x5b3b runnable [0x000000004062c000]
java.lang.Thread.State: RUNNABLE
at java.text.DateFormat.format(DateFormat.java:316)
at com.xxx.foo.services.common.DateFormatUtil.format(DateFormatUtil.java:41)
at com.xxx.foo.shared.monitor.schedule.AppMonitorDataAvgScheduler.run(AppMonitorDataAvgScheduler.java:127)
at com.xxx.foo.services.common.utils.AliTimer$2.run(AliTimer.java:128)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
[2] Busy(26.1%) thread(24018/0x5dd2) stack of java process(23269) under user(admin):
"pool-1-thread-2" prio=10 tid=0x000000005a968800 nid=0x5dd2 runnable [0x00000000420e9000]
java.lang.Thread.State: RUNNABLE
at java.util.Arrays.copyOf(Arrays.java:2882)
at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:100)
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:572)
at java.lang.StringBuffer.append(StringBuffer.java:320)
- locked <0x00000007908d0030> (a java.lang.StringBuffer)
at java.text.SimpleDateFormat.format(SimpleDateFormat.java:890)
at java.text.SimpleDateFormat.format(SimpleDateFormat.java:869)
at java.text.DateFormat.format(DateFormat.java:316)
at com.xxx.foo.services.common.DateFormatUtil.format(DateFormatUtil.java:41)
at com.xxx.foo.shared.monitor.schedule.AppMonitorDataAvgScheduler.run(AppMonitorDataAvgScheduler.java:126)
at com.xxx.foo.services.common.utils.AliTimer$2.run(AliTimer.java:128)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
...
上面的线程栈可以看出,CPU 消耗最高的 2 个线程都在执行 java.text.DateFormat.format,业务代码对应的方法是 shared.monitor.schedule.AppMonitorDataAvgScheduler.run。可以基本确定:
多个执行几次 show-busy-java-threads.sh, 如果上面情况高概率出现,则可以确定上面的判定。
因为调用越少代码执行越快,则出现在线程栈的概率就越低。
分析 shared.monitor.schedule.AppMonitorDataAvgScheduler.run 实现逻辑和调用方式,以优化实现解决问题。
对于线上系统突然产生的运行缓慢问题,如果该问题导致线上系统不可用,那么首先需要做的就是,导出jstack和内存信息,然后重启系统,尽快保证系统的可用性。这种情况可能的原因主要有两种:
相对来说,这是出现频率最高的两种线上问题,而且它们会直接导致系统不可用。另外有几种情况也会导致某个功能运行缓慢,但是不至于导致系统不可用:
对于这三种情况,通过查看CPU和系统内存情况是无法查看出具体问题的,因为它们相对来说都是具有一定阻塞性操作,CPU和系统内存使用情况都不高,但是功能却很慢。
这两条基本上是大部分意外出现的原因,之前项目出现过的一个问题:有个接口响应的实体类中封装了一个集合,由于没有对集合做限制(刚开始数据太少,写代码的同学也没在意),后续每次封装全表数据,导致OOM。
线程堆栈信息
线程堆栈也称线程调用堆栈,是虚拟机中线程(包括锁)状态的一个瞬间快照,即系统在某一个时刻所有线程的运行状态,包括每一个线程的调用堆栈,锁的持有情况。虽然不同的虚拟机打印出来的格式有些不同,但是线程堆栈的信息都包含:
主要可以看到函数的调用关系,通过这个可以快速定位到出问题的代码。
新开应用,由于流量一直不大,集群QPS大概只有5左右,写接口的rt在30ms左右。
之后接入了新的业务,业务方给出的数据是日常QPS可以达到2000,大促峰值QPS可能会达到1万。
后续再压测过程中发现,当单机QPS达到200左右时,接口的rt没有明显变化,但是CPU利用率急剧升高,直到被打满。
压测停止后,CPU利用率立刻降了下来。
排查与解决
使用阿里开源工具Arthas,或者采用JDK自带工具
首先查看CPU的使用情况,可直接使用top命令直接查看:
此时可以看到,进程ID为3480的Java进程占用的CPU比较高,基本可以断定是应用代码执行过程中消耗了大量CPU
排查代码问题,sequence创建和使用有问题
public Long insert(T dataObject) {
if (dataObject.getId() == null) {
Long id = next();
dataObject.setId(id);
}
if (sqlSession.insert(getNamespace() + ".insert", dataObject) > 0) {
return dataObject.getId();
} else {
return null;
}
}
public Sequence sequence() {
return SequenceBuilder.create()
.name(getTableName())
.sequenceDao(sequenceDao)
.build();
}
/**
\* 获取下一个主键ID
*
\* @return
*/
protected Long next() {
try {
return sequence().nextValue();
} catch (SequenceException e) {
throw new RuntimeException(e);
}
}
可以发现我们每次insert语句都重新build了一个新的sequence,这就导致本地缓存就被丢掉了,所以每次都会去数据库中重新拉取1000条,但是只是用了一条,下一次就又重新取了1000条,周而复始
优化方法:
调整代码结构,把Sequence实例的生成改为在应用启动时初始化一次。后面在获取sequence的时候,不会每次都和数据库交互,而是先查本地缓存,本地缓存的耗尽了才会再和数据库交互,获取新的sequence。
public abstract class BaseMybatisDAO implements InitializingBean {
@Override
public void afterPropertiesSet() throws Exception {
sequence = SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build();
}
}
通过实现InitializingBean,并且重写afterPropertiesSet()方法,在这个方法中进行Sequence的初始化。