记一次业务压测过程中的问题

最近在和业务一起做压测，中间陆陆续续还是发现了一些问题，这里也一起汇总一下，看看压测中需要关注什么，也看看业务中常见的一些性能问题。

业务

日志行号

很多时候使用日志框架，都习惯性从网上复制一份日志配置，保证能正常输出就行。

举个栗子：

...
<Appenders>
			<Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}][%t][%level][%C:%L] %m%n"/>
        </Console>
        <RollingFile name="DailyRollingFile" fileName="${log_path}/server-logs.log"
                     filePattern="${log_path}/logs-%d{yyyy-MM-dd}.log">
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}][%t][%level][%C:%L] %m%n"/>
            <TimeBasedTriggeringPolicy/>
        </RollingFile>
</Appenders>
...

其中，%L就是行号输出，这个配置项在日常定位问题时开启还是比较方便的，但是实际的计算成本很高的。

从结果上看，相同的压测并发量及数据集，在关闭行号后，CPU占用减少了9%左右。

无效日志

关闭行号后，发现日志的打印仍会占用5%左右的CPU，看了一下日志和火焰图，发现两个问题：

核心高流量接口，过多无效日志输出
预期内的业务异常，大量打印调用堆栈

其中对于堆栈的输出，如果在日志Pattern Format中没有指定的话，log4j2会默认在尾部追加%xEx来进行异常堆栈的格式化转换。Log4j – Log4j 2 Layouts

%xEx最终通过ExtendedThrowablePatternConverter进行堆栈打印，过程中涉及类加载、依赖JAR读取等操作，也会占用一部分CPU资源（火焰图中看到大约4%）。

如果要关闭所有的异常堆栈打印的话，可以在尾部追加%ex{0}，但是并不建议这样做，在真正出现异常需要定位问题的时候，堆栈还是很有帮助的。所以这里还是建议，对业务异常，日志输出时不打印堆栈；对非预期异常，必须打印堆栈。

出于稳定性的考虑，我们决定在旺季来临时彻底关闭了INFO日志。

在压测中，我们也实际验证关闭后，已经几乎没有这部分的资源占用了。
（图中原log4j的cpu占用已经没有了）

循环调用

最常见的就是循环调用，调用如果涉及HTTP、RPC等，就会导致整体耗时较长。

图中就是一个循环RPC调用的例子，解决方法也比较简单，循环改批量即可。

自建轮子填坑

压测中发现老项目用了一个公司内部的MySQL连接池，发现在获取连接时存在性能瓶颈，在连接数充足的情况下，getConnection耗时较高。

替换连接池后恢复正常。

资源ID设计优化

这次压测中，一个基础服务表的数据量较大，从MySQL迁到了TiDB。

而在TiDB的查询过程中，涉及多个资源ID的IN查询，查找资源ID的供应商及分区信息。由于在TiDB写入时，使用的是默认的自增ID进行Hash，因此数据在TiKV上的分布很随机，IN查询可能涉及多个节点查询，导致性能表现并不好。

其中，SQL平均响应时间最高已经到了17ms，99线也达到40ms以上，涉及多节点的查询也找不到更好的优化方法。

在考虑了缓存、上层业务优化后，我们想到从ID设计下手，可以完全避免这个问题，即在资源ID前预留1个字节（实际4~6bit就可以），将供应商及分区信息写入这个字节，这样从ID上就能直接算出结果，完全避免了数据库查询。

（最终作为了一个长期优化方向，改造周期长，无法在旺季前完成）

第三方

阿里云OSS SDK高并发性能问题

在压测过程中，对慢接口的链路进行追踪，发现耗时都在oss sdk中有一个计算签名的方法里。

实际发现函数中的方法调用耗时都很短，但是整个函数执行时间比较长，所以怀疑是函数中的同步锁操作。

这里细看会发现是进行一个单例对象的的初始化，但是问题出在赋值的是一个函数入参，而Java中函数参数是值传递，所以这里的赋值并不会对调用上层的实际对象赋值，导致每一次进入函数时macInstance都是null。

正常情况下这里并不会有问题，但是在高并发场景下，多线程争夺lock锁就会有性能问题。

我使用的是3.15.0，对比了一下之前几个版本的SDK，发现旧版本2.8.x没有这个问题，应该也是官方的出发点也是想重构代码，把sign方法抽出到一个新的父类中，从而引发了这个问题，目前也已经提了Issue，等官方新版解决吧。（https://github.com/aliyun/aliyun-oss-java-sdk/issues/423）