CPU性能优化干货总结

一、背景

部门成立专项组,对数智平台和站务系统做性能优化,其中目标之一为降低服务端硬件成本,即在32G内存、CPU银牌的配置下,能支撑1万+发客量。要达到此目标,需通过压力测试并配合监控系统,以QPS、RPS、接口响应时间、接口成功率、SQL耗时、JVM运行情况、CPU和内存运行情况等数据指标为依据,找出系统中存在的性能瓶颈。

二、压测准备工作

1、测试服务器

1.1、准备一台测试服务器,配置如下:

硬件类型 硬件配置 备注
CPU i5-9400 CPU @ 2.90GHz @ 6 Core 6 Thread 普通办公电脑
内存 DIMM DDR4 @ 16G 2400Mhz + 8G 2400Mhz ---
硬盘 KINGSTON SA400M8 SSD 240G 性能优于机械硬盘50%
网卡 RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller ---

1.2、准备千兆交换机

因压力机的网卡为100M,当请求超过100user后数据量超过压力机带宽限制,压测数据突发提升,因此更换千兆交换机。

2、CAT监控

为了在压测过程中,实时监控业务系统运行情况,采用了目前中心系统已成熟使用的cat监控,其原理是通过埋点数据上送,并生成各类可视化报表,可监控的指标包括JVM、接口、SQL、异常告警等。
cat官方地址:https://github.com/dianping/cat

三、压测关键过程

1、第一次压测情况

用户数 QPS 压测情况说明 出票量
10 33 CPU80%,tomcat-zw占用15%;影响正常业务 10分钟/3540张
20 27 CPU80%,tomcat-zw占用15%;影响正常业务 10分钟/4440张

CPU负载情况:
CPU性能优化干货总结插图

通过以上数据可以看出,在10个并发请求情况下,CPU基本打满,业务系统已无法正常运行。提升到20个并发请求后,QPS不增返降,说明系统已无法支撑更多请求。

2、数智平台性能排查及解决过程

2.1、接口缓存

  • 以上数据显示,站务系统tomcat-zw仅占用了15%的CPU,需要找到其他65%消耗在哪。
  • 通过top命令发现station-base占用CPU超过tomcat-zw,按照业务复杂度划分来看,及其不合理,于是需要找出station-base占用高的原因。
  • 首先,找到station-base的进程ID:ps -ef | grep station-base
    CPU性能优化干货总结插图1
  • 再查看进程ID找到占用高的线程ID:top -Hp 1061
  • 再根据线程ID找到具体堆栈信息
    线程ID转化为16进制(TID):printf "%xn" TID;
    JVM堆栈中查找线程信息:jstack PID | grep TID -A100;
  • 发现较多线程在执行以下两个接口,但未做缓存:
    /base/openApi/line/getAllLineDownSiteBySiteNos
    /base/openApi/line/getStationLineByLineNo

2.2、网关优化

2.2.1、spring gateway向/tmp文件夹创建大量临时文件夹,导致/tmp目录卡死
  • 使用jstack命令查看吃cpu的线程运行情况如下图:
    CPU性能优化干货总结插图2
  • 登录服务器查看/tmp目录大小,发现存在大量临时文件,乃至ls /tmp 命令卡死
    CPU性能优化干货总结插图3
  • 解决措施:将spring-web 5.2.15升级到5.2.16
2.2.2、自定义过滤器代码本身问题排除
  • 因gateway需要对请求和响应进行参数重新包装,故需要自定义过滤器,分别是请求过滤器(ModifyRequestGatewayFilterFactory)和响应过滤器(ModifyResponseGatewayFilterFactory)进行拦截处理,为避免网关响应时间受自定义过滤器的影响,直接将过滤器取消,对spring cloud gateway原生代码进行请求压测,经实测后,性能并为明显提升,可以排除自定义过滤器的问题。
2.2.3、Reactor(netty)工作线程组及epoll请求处理线程配置

CPU性能优化干货总结插图5

CPU性能优化干货总结插图6

但从接口的平均响应时间来看,依然在500ms左右。于是通过资料查找,怀疑为netty问题,netty源码的配置为:

DEFAULT_IO_WORKER_COUNT:如果环境变量有设置reactor.ipc.netty.workerCount,则用该值;没有设置则取Math.max(Runtime.getRuntime().availableProcessors(), 4)))
DEFAULT_IO_SELECT_COUNT:如果环境变量有设置reactor.ipc.netty.selectCount,则用该值;没有设置则取-1,表示没有selector thread

默认配置下,通过artha可以看出Reactor-http-epoll处理线程如下图:
CPU性能优化干货总结插图7

可以看出,netty框架默认情况下,按测试服务器配置,工作线程为6且未使用selector线程组。于是增加以下环境变量:

    @Bean
    public ReactorResourceFactory reactorClientResourceFactory() {
	     // 配置线程组
        System.setProperty("reactor.netty.ioSelectCount","1");
        // 这里工作线程数为2-4倍都可以。看具体情况
        int ioWorkerCount = Math.max(Runtime.getRuntime().availableProcessors()*3, 4));
        System.setProperty("reactor.netty.ioWorkerCount",String.valueOf(ioWorkerCount);
        return new ReactorResourceFactory();
    }

再次通过arthas可以看出Reactor-http-epoll处理线程如下图:
CPU性能优化干货总结插图8

配置完成后,再次压测,RPS达到3300,平均响应时间降低到150ms以内
CPU性能优化干货总结插图9

2.2.4、logback同步写日志改为异步

通过cpu火焰图发现在处理大量请求时,自定义的sql打印插件频繁的输出sql语句,而且logback在默认情况下采用同步写日志,而同步阻塞写,会拖慢业务方法执行速度,下图是将logback改成异步的配置
CPU性能优化干货总结插图10

2.2.5、网关优化总结

  • 1、自定义过滤器本身问题排除
  • 2、使用centos系统提供的一些硬件资源命令来分析高消耗cpu或者io线程,使用查此线程在jvm中的运行详情以此来寻找问题解决方向
  • 3、分析jvm中的线程来判断定位可能出问题的代码(比如2.2.1)
  • 4、通过关键信息寻找问题原因或解决方案(最好是来自官网或者github官方仓库的issues)
  • 5、透过现象看本质,通过各种辅助工具或命令来排查cpu和io高占用的线程,以此数据作为解决问题的基础支撑

3、站务系统性能排查及解决过程

3.1 全局filter校验token未做缓存

CPU性能优化干货总结插图11

通过链路监控发现,zw-station-ticket模块在接收到购票请求到第一次执行SQL查询之间,有大约600ms损耗。通过查看代码发现,可能是因为全局token校验接口未做缓存导致。优化完成后查看监控数据,token校验耗时正常。

3.2 Transaction注解问题

CPU性能优化干货总结插图12

再次压测,观测调用链路,仍然发现在进入购票接口后,有时间损耗,通过排查代码发现,在购票和锁票方法上面有@Transaction注解,时间损耗的可能原因是:

当 Spring 遇到该注解时,会自动从数据库连接池中获取 connection,并开启事务然后绑定到 ThreadLocal 上,对于@Transactional注解包裹的整个方法都是使用同一个connection连接 。如果我们出现了耗时的操作,比如第三方接口调用,业务逻辑复杂,大批量数据处理等就会导致我们我们占用这个connection的时间会很长,数据库连接一直被占用不释放。

因此去掉事务注解后,再次观测数据,空白时间损耗问题解决。
CPU性能优化干货总结插图13

后续解决思路:对事务方法进行拆分,尽量让事务变小,变快,减小事务的颗粒度。否则,可能出现:

  • 数据库连接池被占满,应用无法获取连接资源;
  • 容易引发数据库死锁;
  • 数据库回滚时间长;
  • 在主从架构中会导致主从延时变大。

3.3 logback日志问题

通过以上方式优化完成后,发现tomcat-zw模块依然占用比较大的CPU,在150%-300%之间。于是,准备通过async-profiler工具,查看耗CPU的详细堆栈信息。

  • 第一步,下载async-profiler-2.8.3-linux-x64.tar.gz,并解压
  • 第二步,执行数据采集命令,生成CPU运行火焰图:./profiler.sh -d 60 -f ./nacos.html PID

CPU性能优化干货总结插图14

通过火焰图发现,基本所有CPU都在执行logback日志打印。
于是,对logback配置文件进行优化:

  • 去掉控制台打印
  • 改为异步合并写日志

CPU性能优化干货总结插图15

优化完成后再次压测,RPS由原23.7提高到222;平均响应时间由原1447ms降低为1082ms;
优化前:
CPU性能优化干货总结插图16

优化后:
CPU性能优化干货总结插图17

4、其他优化

  • 为减少CPU消耗,JVM垃圾收集器由CMS改为G1

文章来源于互联网:CPU性能优化干货总结

THE END
分享
二维码