前往小程序,Get更优阅读体验!
立即前往
首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >CRUDBoy成长计划(6)— CPU100%优秀笔记汇总

CRUDBoy成长计划(6)— CPU100%优秀笔记汇总

作者头像
鹿老师的Java笔记
发布2022-01-20 13:22:26
2530
发布2022-01-20 13:22:26
举报

CRUDBoy成长计划(6)— CPU100%优秀笔记汇总

注意:

  1. 本次计划针对有一定工作经验,想要提升技术和工作能力的程序员。
  2. 关于本计划的详情见:CRUD Boy 成长计划
  3. 宗旨 首先不做理论知识普及,这样的东西太多了,其次,不做自我感动的事情,看上去学了很久,实际上工作用不到,面试问不到。 最后功利的一点说就是为了提高薪资。为了能够在工作中有更好的表现,将代码写的更好,更易用,更好维护,更优雅。也为了,在下一次面试的时候,能够从一群八股文科举选手中脱颖而出。 归根结底,技术岗位最重要的还是解决问题的能力,而不是背书的能力。 由于每个人的经验都是不可复制的,因此,我们需要互相学习互相探索出一条程序员自我成长的路线。整体方向围绕两个核心 职业素养 和 技术能力开展。既为了现在能够把代码写好,把需求做好,也为了日后能够把牛逼吹好,把薪资谈好。

本周主题:CPU 100%的时候怎么办?

由于本周大家的笔记过于精彩,因此就出个合集好了,分享一下优秀的笔记。互相学习。

笔记汇总

由于大家的排查过程都是类似的,直接放之前收藏的博客了

服务器问题排查手册之高 CPU 占用

该手册用于排查 Java 项目的 CPU 性能问题(top us 值过高),根据线程 id 逐步找到并打印出问题线程栈,从而确定导致性能问题的方法调用。 一个应用占用 CPU 很高,除了确实是计算密集型应用之外,也有可能是出现了死循环。 解决思路/方案

  1. top 命令找出有问题 Java 进程及线程 id:
    1. 开启线程显示模式
    2. 按 CPU 使用率排序
    3. 记下 Java 进程 id 及其 CPU 高的线程 id
  2. 用进程 id 作为参数,jstack 有问题的 Java 进程
  3. 手动转换线程 id 成十六进制(可以用 printf %x 1234)
  4. 查找十六进制的线程 id(可以用 grep)
  5. 查看对应的线程栈

下面我们出现的一个实际故障为例,介绍怎么定位和解决这类问题。

根据 top 命令,发现测试环境 PID 为 5989 的 Java 进程占用 CPU 高达 100%, 疑似故障。但是,怎么定位到具体线程或者代码呢?

image-20211230174244190

首先显示线程列表:

代码语言:javascript
复制
ps -mp pid -o THREAD,tid,time

image-20211230174320441

找到了耗时最高的线程 6048,占用 CPU 时间已经两个小时了

其次将需要的线程 ID 转换为 16 进制格式:

代码语言:javascript
复制
printf "%x\n" tid

image-20211230174346931

最后打印线程的堆栈信息

代码语言:javascript
复制
jstack pid | grep tid -A 30

image-20211230174413323

找到了出现问题的代码堆栈信息, 至于具体怎么修改就看具体业务逻辑,这里不做展开讨论.

总结下排查 CPU 故障的方法和技巧有哪些:

  • top 命令:可以查看实时的 CPU 使用情况, 也可以查看最近一段时间的 CPU 使用情况. 思考
    • 如何开启线程显示模式
    • 如何按CPU使用率排序
    • 如何按内存使用大小排序
  • PS 命令:强大的进程状态监控命令, 可以查看进程以及进程中线程的当前 CPU 使用情况, 属于当前状态的采样数据.
  • jstack:Java 提供的命令. 可以查看某个进程的当前线程栈运行情况, 根据这个命令的输出可以定位某个进程的所有线程的当前运行状态、运行代码,以及是否死锁等等.
  • pstack:Linux 命令. 可以查看某个进程的当前线程栈运行情况.

最后, 实际工程中会要多次这样操作以确定问题,上面过程太繁琐了, 分享一个脚本给大家:

该脚本用于快速排查 Java 的 CPU 性能问题(top us 值过高),自动查出运行的 Java 进程中消耗 CPU 多的线程,并打印出其线程栈,从而确定导致性能问题的方法调用。

代码语言:javascript
复制
#!/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

用法

代码语言:javascript
复制
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

示例

代码语言:javascript
复制
$ 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。可以基本确定:

  • AppMonitorDataAvgScheduler.run 调用 DateFormat.format 次数比较频繁。
  • DateFormat.format 比较慢。(这个可以由 DateFormat.format 的实现确定。)

多个执行几次 show-busy-java-threads.sh, 如果上面情况高概率出现,则可以确定上面的判定。

因为调用越少代码执行越快,则出现在线程栈的概率就越低。

分析 shared.monitor.schedule.AppMonitorDataAvgScheduler.run 实现逻辑和调用方式,以优化实现解决问题。

基本概念

对于线上系统突然产生的运行缓慢问题,如果该问题导致线上系统不可用,那么首先需要做的就是,导出jstack和内存信息,然后重启系统,尽快保证系统的可用性。这种情况可能的原因主要有两种:

  • 代码中某个位置读取数据量较大,导致系统内存耗尽,从而导致Full GC次数过多,系统缓慢;
  • 代码中有比较耗CPU的操作,导致CPU过高,系统运行缓慢;

相对来说,这是出现频率最高的两种线上问题,而且它们会直接导致系统不可用。另外有几种情况也会导致某个功能运行缓慢,但是不至于导致系统不可用:

  • 代码某个位置有阻塞性的操作,导致该功能调用整体比较耗时,但出现是比较随机的;
  • 某个线程由于某种原因而进入WAITING状态,此时该功能整体不可用,但是无法复现;
  • 由于锁使用不当,导致多个线程进入死锁状态,从而导致系统整体比较缓慢。

对于这三种情况,通过查看CPU和系统内存情况是无法查看出具体问题的,因为它们相对来说都是具有一定阻塞性操作,CPU和系统内存使用情况都不高,但是功能却很慢。

  • 代码中某个位置读取数据量较大,导致系统内存耗尽,从而导致Full GC次数过多,系统缓慢;
  • 代码中有比较耗CPU的操作,导致CPU过高,系统运行缓慢;

这两条基本上是大部分意外出现的原因,之前项目出现过的一个问题:有个接口响应的实体类中封装了一个集合,由于没有对集合做限制(刚开始数据太少,写代码的同学也没在意),后续每次封装全表数据,导致OOM。

线程堆栈信息

线程堆栈也称线程调用堆栈,是虚拟机中线程(包括锁)状态的一个瞬间快照,即系统在某一个时刻所有线程的运行状态,包括每一个线程的调用堆栈,锁的持有情况。虽然不同的虚拟机打印出来的格式有些不同,但是线程堆栈的信息都包含:

  • 线程名字,id,线程的数量等。
  • 线程的运行状态,锁的状态(锁被哪个线程持有,哪个线程在等待锁等)
  • 调用堆栈(即函数的调用层次关系)调用堆栈包含完整的类名,所执行的方法,源代码的行数。

主要可以看到函数的调用关系,通过这个可以快速定位到出问题的代码。

案例

新开应用,由于流量一直不大,集群QPS大概只有5左右,写接口的rt在30ms左右。

之后接入了新的业务,业务方给出的数据是日常QPS可以达到2000,大促峰值QPS可能会达到1万。

后续再压测过程中发现,当单机QPS达到200左右时,接口的rt没有明显变化,但是CPU利用率急剧升高,直到被打满。

压测停止后,CPU利用率立刻降了下来。

排查与解决

使用阿里开源工具Arthas,或者采用JDK自带工具

首先查看CPU的使用情况,可直接使用top命令直接查看

此时可以看到,进程ID为3480的Java进程占用的CPU比较高,基本可以断定是应用代码执行过程中消耗了大量CPU

排查代码问题,sequence创建和使用有问题

代码语言:javascript
复制

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。

代码语言:javascript
复制
public abstract class BaseMybatisDAO implements InitializingBean {
        @Override
        public void afterPropertiesSet() throws Exception {
            sequence = SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build();
        }
    }

通过实现InitializingBean,并且重写afterPropertiesSet()方法,在这个方法中进行Sequence的初始化。

本文参与 腾讯云自媒体分享计划,分享自微信公众号。
原始发表:2021-12-30,如有侵权请联系 cloudcommunity@tencent.com 删除

本文分享自 鹿小洋的Java笔记 微信公众号,前往查看

如有侵权,请联系 cloudcommunity@tencent.com 删除。

本文参与 腾讯云自媒体分享计划  ,欢迎热爱写作的你一起参与!

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • CRUDBoy成长计划(6)— CPU100%优秀笔记汇总
    • 本周主题:CPU 100%的时候怎么办?
      • 笔记汇总
        • 由于大家的排查过程都是类似的,直接放之前收藏的博客了
        • 基本概念
        • 案例
    领券
    问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档