• 线上应用故障排查之一:高CPU占用


    一个应用占用CPU很高,除了确实是计算密集型应用之外,通常原因都是出现了死循环。(友情提示:本博文章欢迎转载,但请注明出处:hankchen,http://www.blogjava.net/hankchen

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

    根据top命令,发现PID为28555的Java进程占用CPU高达200%,出现故障。

    通过ps aux | grep PID命令,可以进一步确定是tomcat进程出现了问题。但是,怎么定位到具体线程或者代码呢?

    首先显示线程列表:

    ps -mp pid -o THREAD,tid,time

    找到了耗时最高的线程28802,占用CPU时间快两个小时了!

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

    printf "%x " tid

    最后打印线程的堆栈信息:

    jstack pid |grep tid -A 30

    找到出现问题的代码了!

    现在来分析下具体的代码:ShortSocketIO.readBytes(ShortSocketIO.java:106)

    ShortSocketIO是应用封装的一个用短连接Socket通信的工具类。readBytes函数的代码如下:

    public byte[] readBytes(int length) throws IOException {
    
        if ((this.socket == null) || (!this.socket.isConnected())) {
    
            throw new IOException("++++ attempting to read from closed socket");
    
        }
    
        byte[] result = null;
    
        ByteArrayOutputStream bos = new ByteArrayOutputStream();
    
        if (this.recIndex >= length) {
    
               bos.write(this.recBuf, 0, length);
    
               byte[] newBuf = new byte[this.recBufSize];
    
               if (this.recIndex > length) {
    
                   System.arraycopy(this.recBuf, length, newBuf, 0, this.recIndex - length);
    
               }
    
               this.recBuf = newBuf;
    
               this.recIndex -= length;
    
        } else {
    
               int totalread = length;
    
               if (this.recIndex > 0) {
    
                    totalread -= this.recIndex;
    
                    bos.write(this.recBuf, 0, this.recIndex);
    
                    this.recBuf = new byte[this.recBufSize];
    
                    this.recIndex = 0;
    
        }
    
        int readCount = 0;
    
    while (totalread > 0) {
    
             if ((readCount = this.in.read(this.recBuf)) > 0) {
    
                    if (totalread > readCount) {
    
                          bos.write(this.recBuf, 0, readCount);
    
                          this.recBuf = new byte[this.recBufSize];
    
                          this.recIndex = 0;
    
                   } else {
    
                         bos.write(this.recBuf, 0, totalread);
    
                         byte[] newBuf = new byte[this.recBufSize];
    
                         System.arraycopy(this.recBuf, totalread, newBuf, 0, readCount - totalread);
    
                         this.recBuf = newBuf;
    
                         this.recIndex = (readCount - totalread);
    
                 }
    
                 totalread -= readCount;
    
            }
    
       }
    
    }

    问题就出在标红的代码部分。如果this.in.read()返回的数据小于等于0时,循环就一直进行下去了。而这种情况在网络拥塞的时候是可能发生的。

    至于具体怎么修改就看业务逻辑应该怎么对待这种特殊情况了。

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

    1、top命令:Linux命令。可以查看实时的CPU使用情况。也可以查看最近一段时间的CPU使用情况。

    2、PS命令:Linux命令。强大的进程状态监控命令。可以查看进程以及进程中线程的当前CPU使用情况。属于当前状态的采样数据。

    3、jstack:Java提供的命令。可以查看某个进程的当前线程栈运行情况。根据这个命令的输出可以定位某个进程的所有线程的当前运行状态、运行代码,以及是否死锁等等。

    4、pstack:Linux命令。可以查看某个进程的当前线程栈运行情况。

    解决方案

    1. 排查应用是否创建了过多的线程

    通过jstack确定应用创建了多少线程?超量创建的线程的堆栈信息是怎样的?谁创建了这些线程?一旦明确了这些问题,便很容易解决。

    2. 调整操作系统线程数阈值 操作系统会限制进程允许创建的线程数,使用ulimit -u命令查看限制。某些服务器上此阈值设置的过小,比如1024。一旦应用创建超过1024个线程,就会遇到java.lang.OutOfMemoryError: unable to create new native thread问题。如果是这种情况,可以调大操作系统线程数阈值。

    3. 增加机器内存 如果上述两项未能排除问题,可能是正常增长的业务确实需要更多内存来创建更多线程。如果是这种情况,增加机器内存。

    4. 减小堆内存 一个老司机也经常忽略的非常重要的知识点:线程不在堆内存上创建,线程在堆内存之外的内存上创建。所以如果分配了堆内存之后只剩下很少的可用内存,依然可能遇到java.lang.OutOfMemoryError: unable to create new native thread。考虑如下场景:系统总内存6G,堆内存分配了5G,永久代512M。在这种情况下,JVM占用了5.5G内存,系统进程、其他用户进程和线程将共用剩下的0.5G内存,很有可能没有足够的可用内存创建新的线程。如果是这种情况,考虑减小堆内存。

    5. 减少进程数 这和减小堆内存原理相似。考虑如下场景:系统总内存32G,java进程数5个,每个进程的堆内存6G。在这种情况下,java进程总共占用30G内存,仅剩下2G内存用于系统进程、其他用户进程和线程,很有可能没有足够的可用内存创建新的线程。如果是这种情况,考虑减少每台机器上的进程数。

    6. 减小线程栈大小

    线程会占用内存,如果每个线程都占用更多内存,整体上将消耗更多的内存。每个线程默认占用内存大小取决于JVM实现。可以利用-Xss参数限制线程内存大小,降低总内存消耗。例如,JVM默认每个线程占用1M内存,应用有500个线程,那么将消耗500M内存空间。如果实际上256K内存足够线程正常运行,配置-Xss256k,那么500个线程将只需要消耗125M内存。(注意,如果-Xss设置的过低,将会产生java.lang.StackOverflowError错误)

    实战

    1、问题背景

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

    2、排查思路

    2.1 定位高负载进程 pid

    首先登录到服务器使用top命令确认服务器的具体情况,根据具体情况再进行分析判断。

     通过观察load average,以及负载评判标准(8核),可以确认服务器存在负载较高的情况;

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

    2.2 定位具体的异常业务

    这里咱们可以使用 pwdx 命令根据 pid 找到业务进程路径,进而定位到负责人和项目:

     可得出结论:该进程对应的就是数据平台的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 步还是太繁琐耗时了,之前介绍过淘宝的oldratlee 同学就将上面的流程封装为了一个工具:show-busy-java-threads.sh,可以很方便的定位线上的这类问题:

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

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

    3、根因分析

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

    • 异常方法逻辑:是把时间戳转成对应的具体的日期时间格式;
    • 上层调用:计算当天凌晨至当前时间所有秒数,转化成对应的格式放入到set中返回结果;
    • 逻辑层:对应的是数据平台实时报表的查询逻辑,实时报表会按照固定的时间间隔来,并且在一次查询中有多次(n次)方法调用。

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

    4、解决方案

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

    5、总结

    • 在编码的过程中,除了要实现业务的逻辑,也要注重代码性能的优化。一个业务需求,能实现,和能实现的更高效、更优雅其实是两种截然不同的工程师能力和境界的体现,而后者也是工程师的核心竞争力。
    • 在代码编写完成之后,多做 review,多思考是不是可以用更好的方式来实现。
    • 线上问题不放过任何一个小细节!细节是魔鬼,技术的同学需要有刨根问题的求知欲和追求卓越的精神,只有这样,才能不断的成长和提升。
  • 相关阅读:
    动态页面技术(JSP/EL/JSTL)
    JavaWeb核心之Servlet
    会话技术Cookie&Session
    待整理
    二进制中1的个数(python)
    矩形覆盖(python)
    变态跳台阶(python)
    跳台阶(python)
    斐波那契数列(python)
    旋转数组的最小数字(python/c++)
  • 原文地址:https://www.cnblogs.com/edda/p/13578857.html
Copyright © 2020-2023  润新知