一、问题背景

工作中当你服务器CPU达到100%时，该如何排查异常故障呢？

突然收到运维邮件报警，显示数据平台服务器cpu利用率达到了98.94%，而且最近一段时间一直持续在70%以上，看起来像是硬件资源到瓶颈需要扩容了，但仔细思考就会发现咱们的业务系统并不是一个高并发或者CPU密集型的应用，这个利用率有点太夸张，硬件瓶颈应该不会这么快就到了，一定是哪里的业务代码逻辑有问题。

二、排查思路

2.1 定位高负载进程 pid
首先登录到服务器使用top命令确认服务器的具体情况，根据具体情况再进行分析

image.png

通过观察load average，以及负载评判标准（8核），可以确认服务器存在负载较高的情况；

image.png

观察各个进程资源使用情况，可以看出进程id为682的进程，有着较高的CPU占比。

2.2 定位具体的异常业务
这里咱们可以使用 pwdx 命令根据 pid 找到业务进程路径，进而定位到负责人和项目：

image.png

可得出结论：该进程对应的就是数据平台的web服务。

2.3 定位异常线程及具体代码行

传统的方案一般是4步：

• 1、top oder by with P：1040 // 首先按进程负载排序找到 maxLoad(pid)

• 2、top -Hp 进程PID：1073 // 找到相关负载 线程PID

• 3、printf "0x%x " 线程PID： 0x431 // 将线程PID转换为 16进制，为后面查找 jstack 日志做准备

• 4、jstack 进程PID | vim +/十六进制线程PID - // 例如：jstack 1040|vim +/0x431 -

但是对于线上问题定位来说，分秒必争，上面的 4 步还是太繁琐耗时了！

将上面的流程封装为了一个工具：show-busy-java-threads.sh，可以很方便的定位线上的这类问题：

image.png

可得出结论：是系统中一个时间工具类方法的执行cpu占比较高，定位到具体方法后，查看代码逻辑是否存在性能问题。

如果线上问题比较紧急，可以省略 2.1、2.2 直接执行 2.3，这里从多角度剖析只是为了给大家呈现一个完整的分析思路。

$ wget --no-check-certificate https://raw.githubusercontent.com/superhj1987/awesome-scripts/master/java/bin/show-busy-java-threads
    
$ chmod +x show-busy-java-threads

$ ./show-busy-java-threads

cat show-busy-java-threads.sh

#!/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 Jerry Lee

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

# 从 所有的 Java进程中找出最消耗CPU的线程（缺省5个），打印出其线程栈
show-busy-java-threads.sh

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

三、根因分析

经过前面的分析与排查，最终定位到一个时间工具类的问题，造成了服务器负载以及cpu使用率的过高。

• 异常方法逻辑：是把时间戳转成对应的具体的日期时间格式；

• 上层调用：计算当天凌晨至当前时间所有秒数，转化成对应的格式放入到set中返回结果；

• 逻辑层：对应的是数据平台实时报表的查询逻辑，实时报表会按照固定的时间间隔来，并且在一次查询中有多次（n次）方法调用。

那么可以得到结论，如果现在时间是当天上午10点，一次查询的计算次数就是 106060n次=36,000n次计算，而且随着时间增长，越接近午夜单次查询次数会线性增加。由于实时查询、实时报警等模块大量的查询请求都需要多次调用该方法，导致了大量CPU资源的占用与浪费。

四、解决方案

定位到问题之后，首先考虑是要减少计算次数，优化异常方法。排查后发现，在逻辑层使用时，并没有使用该方法返回的set集合中的内容，而是简单的用set的size数值。确认逻辑后，通过新方法简化计算（当前秒数-当天凌晨的秒数），替换调用的方法，解决计算过多的问题。上线后观察服务器负载和cpu使用率，对比异常时间段下降了30倍，恢复至正常状态，至此该问题得已解决。

image.png

五、总结

在编码的过程中，除了要实现业务的逻辑，也要注重代码性能的优化。一个业务需求，能实现，和能实现的更高效、更优雅其实是两种截然不同的工程师能力和境界的体现，而后者也是工程师的核心竞争力。

在代码编写完成之后，多做 review，多思考是不是可以用更好的方式来实现。

线上问题不放过任何一个小细节，细节是魔鬼，技术的同学需要有刨根问题的求知欲和追求卓越的精神，只有这样，才能不断的成长和提升。

六、参考

awesome-scripts
https://github.com/superhj1987/awesome-scripts

useful scripts
https://github.com/oldratlee/useful-scripts

线上问题定位工具，CPU 负载特别高的问题排查分析工具
https://www.cnblogs.com/jovic/p/14882664.html