记一次压测QPS上不去的排查经历

背景

由于架构变更,服务与服务之间职责发生变更,故而进行项目重构,而个人中心,是一个重要的入口,该接口开发后,需要进行压测,并结合线上的访问量,进而评估所需要的资源

问题

压测过程中,随着并发数的增加,CPU占用越来越高,但是TPS却依旧没有什么变化,对比之前老系统的压测结果,明显就有异常

因为下游系统并不是直接调用真实系统,而是mock,之前也有这种情况,mock占用资源导致TPS上不去的情况,所以让测试将下游系统也部署上去,真实调用下游看看压测结果,发现还是一样,没有改变

排查

1.通过日志排查

因为能直接接触到的,就是日志了,通过日志分析接口,发现大部分接口耗时都好几秒,然后看调用下游,调用redis前后的日志,发现调用的耗时其实算是正常的;去看其他日志的打印间隔,发现有两行日志之间的时间间隔比较大,定位到代码具体位置,发现这两行日志之间其实都没啥逻辑,对比该接口其他日志结果,发现耗时的地方并不相同,猜想是full gc导致的停顿

2.通过gc日志验证猜想

找到gc日志,查询到所有full gc的日志,发现确实full gc挺频繁的,但是光看gc日志,并不能得出什么信息

3.通过工具定位原因

使用jdk自带的监测工具jvisualvm.exe(jdk/bin目录中)

连接到远程应用,需要应用启动的时候增加JVM参数,暴露出端口,才可以通过下图红框来连接,这里通过本地连接做个样例

连接后,整个界面大概就是这样,首页的看板,可以实时反应出CPU,堆情况等信息

当时CPU的情况大概如下图红线(所有图标,都大概画了当时的情形,以红线为准

压测的整个过程,CPU直接满载了,并且居高不下,一直到压测结束,才降下来

看堆的情况,发现gc频繁,但是gc的曲线如下图红线,每次触发gc后,都只回收一部分,另一部分回收不掉,堆内存持续增长。这样应用运行久了,肯定会内存溢出的。

初步猜测,应该是一直产生大对象,并且被长时间持有,释放不了

通过抽样器,大概反应出堆的情况,发现并没有持有大对象,没有异常的情况,就很奇怪,为什么一直堆一直回收不了,一直持续增长?

下图只是说明在哪里看,给个示例

观察一下CPU的情况,发现有几个方法,一直占用了大量的CPU资源,而且都是日志打印的方法,这就很不对劲了

代码定位到具体的类,发现是做日志脱敏的日志扩展类

下图只是说明在哪里看,给个示例

所以到这里可以初步认定是日志脱敏消耗了大量的CPU资源导致的

4.验证结论

尝试着关掉日志脱敏,重新进行压测,发现压测结果正常,随着并发数的增加,TPS也增加了,CPU正常上升,不存在大量接口延时的情况

观察堆的情况,发现垃圾回收没有那么频繁了,并且触发垃圾回收后,也能回收掉所有垃圾,如下图红线,很平稳,不像之前堆内存一直在持续增长,所以这里验证了前一步的猜想,是日志脱敏导致的

5.解决方案

由于监管要求,日志脱敏并不能关闭,所以得另外找解决办法,既然是日志脱敏消耗大量的CPU资源,那只能对日志进行处理了

分析发现,因为内部框架对于请求/响应报文重复打印了好几次,并且有两个接口,是存在大报文的(由于工作量原因,某些配置表当期没安排迁移,只能通过老系统提供接口,获取整个配置表)

尝试着把这两个接口的配置都清空,开启日志脱敏的情况下,再进行压测,发现堆内存变化也是正常的

因为配置表暂时没人力可以做迁移,最后只能推动框架的负责人,优化日志,减少日志重复打印,避免日志脱敏占用大量CPU资源,但是隐患依旧是存在的,后续推动配置表的迁移

原因

日志脱敏,因为需要做正则匹配,但是大量的日志,以及都是大报文,会消耗特别多的CPU资源

系统是对C的,为了减少延迟,使用的是CMS垃圾回收器

CMS垃圾回收器,触发一次full gc,只会在初期暂停所有应用线程,标记没有被引用的对象,后面并发标记和并发回收,并不会暂停应用,这样是为了减少应用的延迟时间,但由于CPU资源被日志脱敏大量消耗了,导致垃圾回收线程抢占不到CPU资源,回收缓慢,旧垃圾没回收完,新垃圾又产生,堆内存就呈现出持续增长的情况

试中计算每秒查询数(Queries Per Second,QPS)时,核心目标是衡量系统在单位时间内能够处理的请求数量。这一指标常用于评估服务器性能,特别是在高并发场景下的响应能力。 ### QPS 的基本定义与计算方法 QPS 表示每秒可以完成的请求数,其计算公式如下: $$ \text{QPS} = \frac{\text{总请求数}}{\text{试时间(秒)}} $$ 例如,在一个持续时间为 60 秒的试中,如果系统总共处理了 12,000 个请求,则 QPS 为: ```python qps = 12000 / 60 # 输出:200 ``` 这意味着系统平均每秒处理了 200 个请求。 ### 考虑并发量与平均响应时间的关系 QPS 也可以通过并发量和平均响应时间之间的关系进行推导: $$ \text{QPS} = \frac{\text{并发量}}{\text{平均响应时间}} $$ 假设试过程中有 500 个并发请求,每个请求的平均响应时间为 2.5 秒,则: ```python qps = 500 / 2.5 # 输出:200 ``` 这表明系统在该负载下仍能维持每秒 200 个请求的处理能力[^1]。 ### 实际试中的统计方法 在实际试环境中,可以通过日志文件或监控工具来统计 QPS。例如,在 Linux 系统中,可以通过分析日志文件并提取特定时间戳的信息来计算每秒的请求数量: ```bash # 假设日志格式中包含时间戳,且每行代表一个请求 cat access.log | awk '{print $4}' | cut -d: -f2 | sort | uniq -c | sort -nr | head -n 10 ``` 此命令会输出每分钟内每秒钟的请求计数,从而帮助估算 QPS。 此外,还可以使用专门的工具如 `ab` (Apache Bench)、`wrk` 或 `JMeter` 来直接获取 QPS 指标。例如,使用 `ab` 工具进行试的命令如下: ```bash ab -n 10000 -c 500 http://example.com/ ``` 其中 `-n` 表示总请求数,`-c` 表示并发用户数。执行完成后,`ab` 会输出包括 QPS 在内的多个性能指标。 ### 总结 在试中,QPS 是衡量系统吞吐能力的重要指标。可以通过以下方式计算: 1. **基于总请求数与试时间**: ```python qps = total_requests / test_duration_seconds ``` 2. **基于并发量与平均响应时间**: ```python qps = concurrent_users / average_response_time ``` 结合实际环境中的日志分析工具或工具,可以更精确地获取 QPS 数据,并据此优化系统性能。 ---
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值