文档

排查CPU使用率较高的问题

更新时间:

本文介绍如何通过持续剖析排查CPU使用率较高的问题并优化相关代码。

环境准备

示例代码:Spring Boot图书馆应用,包含一个查询所有书(约5万本)的总页数的Rest API。

相关命令

代码

编译方式

mvn clean package

JVM启动参数

-Dserver.port=8888 -XX:+UseConcMarkSweepGC -XX:ParallelGCThreads=2 -XX:ActiveProcessorCount=4 -XX:CMSInitiatingOccupancyFraction=72 -XX:+DisableExplicitGC -Xmx1g -jar demo-0.0.1-SNAPSHOT.jar

调用方式

  • 单次调用:

    curl 'http://localhost:8888/countAllBookPages'
  • 多次调用:

    ab -c 4 -n 100 'http://localhost:8888/countAllBookPages'

问题现象

调用HTTP接口countAllBookPages,通过返回结果可以发现接口的平均响应时间是8.8秒左右,调用较慢。

ab -c 4 -n 100 http://localhost:8888/countAllBookPages

返回示例:

Time per request:       8818.986 [ms] (mean, across all concurrent requests)

问题定位

  1. 登录ARMS控制台,在左侧导航栏选择应用监控 > 应用列表

  2. 应用列表页面顶部选择目标地域,然后单击目标应用名称。

    说明

    语言列显示Java图标图标的应用为接入应用监控的应用,显示-图标的应用为接入可观测链路 OpenTelemetry 版的应用。

  3. 在左侧导航栏中单击持续剖析

  4. 持续剖析页面选择目标快照时间后单击聚合分析,然后在快照详情面板单击Table

    如下图所示,可以发现java.util.LinkedList.node(int)方法在CPU上执行的时间最长,但从表格上看不到调用关系,无法找到问题代码的位置。

    场景二诊断分析

  5. 快照详情面板单击Flamegraph查看火焰图。

    如下图所示,可以看到最占用CPU的方法是java.util.LinkedList.node(int),并且可以看到它的调用方法是com.example.demo.DemoController.countAllBookPages(List)

    场景二火焰图

    结合示例源代码可以发现countAllBookPages方法的入参是书籍列表,此方法会遍历每本书,读取每本书的页数,并累加到总和中。

    countAllBookPages方法之所以占用了如此多的CPU,是因为List<Book> list实际上是LinkedList,其优点是插入和修改较快,但查找很慢。LinkedList的查找要从第一个元素开始,顺着引用关系逐个往后找,时间复杂度是O(n)。因此countAllBookPages方法需要从list中查找出每本书,比较容易遇到性能问题。

    @RestController
    public class DemoController {
        @GetMapping("/countAllBookPages")
        public ResultData<Long> index() {
            long start = System.currentTimeMillis();
            List<Book> list = queryAllBooks();
            long pageCount = countAllBookPages(list);
            return new ResultData<>(pageCount, System.currentTimeMillis() - start);
        }
    
        private List<Book> queryAllBooks() {
            Random random = new Random();
            List<Book> list = new LinkedList<>();
            for (int i = 0; i < 1024 * 50; i++) {
                list.add(new Book("Book" + i, 200 + random.nextInt(100)));
            }
            return list;
        }
    
        private long countAllBookPages(List<Book> list) {
            if (list == null || list.isEmpty()) {
                return 0;
            }
    
            long count = 0;
            for (int i = 0; i < list.size(); i++) {
                count += list.get(i).getPageCount();
            }
            return count;
        }
        }

解决方案

通过问题定位已确认是由于LinkedList的查找较慢引起的问题,因此可以通过以下两个方法优化代码。

方法一

使用ArrayList替换LinkedListArrayList的优点是插入和修改较慢,但查找很快,查找的时间复杂度为O(1)。

    private List<Book> queryAllBooks() {
        Random random = new Random();
        List<Book> list = new ArrayList<>();
        for (int i = 0; i < 1024 * 50; i++) {
            list.add(new Book("Book" + i, 200 + random.nextInt(100)));
        }
        return list;
    }

运行测试,发现接口平均响应时间缩短到了7.7毫秒(返回示例中第19行),相比于原来的8.8秒,速度提升了1000倍以上。

ab -c 4 -n 100 http://localhost:8888/countAllBookPages

返回示例:

Benchmarking localhost (be patient).....done


Server Software:
Server Hostname:        localhost
Server Port:            8888

Document Path:          /countAllBookPages3
Document Length:        38 bytes

Concurrency Level:      4
Time taken for tests:   0.193 seconds
Complete requests:      100
Failed requests:        83
(Connect: 0, Receive: 0, Length: 83, Exceptions: 0)
Total transferred:      14217 bytes
HTML transferred:       3717 bytes
Requests per second:    517.84 [#/sec] (mean)
Time per request:       7.724 [ms] (mean)
Time per request:       1.931 [ms] (mean, across all concurrent requests)
Transfer rate:          71.90 [Kbytes/sec] received

方法二

countAllBookPages中修改遍历LinkedList的方法,改为Enhanced for语句,这种语法会对LinkedList使用Iterator的方式进行遍历,遍历速度较快。

private long countAllBookPages(List<Book> list) {
    if (list == null || list.isEmpty()) {
        return 0;
    }

    long count = 0;
    for (Book book : list) {
        count += book.getPageCount();
    }
    return count;
}

运行测试,发现接口平均响应时间缩短到了8.9毫秒,相比于原来的8.8秒,速度也提升了1000倍左右。

返回示例:

Time per request:       8.913 [ms] (mean)
  • 本页导读 (1)
文档反馈