我们前段时间上线了一个新的应用，因为流量一直不大，集群QPS只有5左右，写接口的rt在30ms左右。因为最近接入了一个新业务，业务方给出的数据是日QPS可以达到2000，大促峰值QPS可能达到10000。因此，为了评估水位，我们进行了压力测试。压测时发现，当单机QPS达到200左右时，界面的rt没有明显变化，但CPU占用率急剧上升，直至满载。压力测试停止后，CPU使用率立即下降。于是开始排查是什么原因导致CPU飙升。故障处理与解决压力测试时，登录机器开始故障处理。本案的调查过程是使用阿里巴巴开源的Arthas工具进行的。除了使用Arthas，还可以使用JDK自带的命令。在开始调查之前，您可以先查看CPU使用率。最简单的方法是直接使用top命令查看：top-10:32:38up11days,17:56,0users,loadaverage:0.84,0.33,0.18Tasks:23total,1running,21sleeping,0stopped,1zombie%Cpu(s):95.5us,2.2sy,0.0ni,76.3id,0.0wa,0.0hi,0.0si,6.1stKiBMem:8388608total,4378768free,3605932used,403908buff/cacheKiBSwap:0total,0free,0used.4378768avail%CPURTMEMIDRESUSERTIME%4378768availCPNIPIDRESUSERCOMMAND3480admin20075656242.9g8976S241.235.8649:07.23java1502root200401768402289084S1.00.539:21.65ilogtail181964root20037564081043928464S0.71.20:39.38java496root2002344224141084396S0.30.252:22.25staragentd1400admin20021769522291565940S0.32.731:13.13java235514root39192204632157046844S0.30.255:34.43argusagent236226root2005583693046888S0.30.112:01.91systemd-JourncanseethattheJavaprocesswithaprocessID3480的占用CPU比较高。可以得出结论，在应用程序代码的执行过程中消耗了大量的CPU。接下来开始查看是哪个线程、哪段代码占用CPU较多。首先下载Arthas命令：curl-Lhttp://start.alibaba-inc.com/install.sh|shstart./as.sh使用Arthas命令“thread-n3-i1000”查看当前“busiest”（CPU消耗）三个线程：从上面的堆栈信息可以看出，占用CPU资源的线程主要卡在了JDBC底层的TCPsocket读取上。连续执行了很多次，发现很多线程都卡在了这个地方。通过分析调用链，我发现这个地方是我代码中数据库的插入，我使用TDDL（阿里内部分布式数据库中间件）创建序列，在序列创建过程中需要和数据库进行交互。但是基于对TDDL的理解，TDDL每次从数据库中查询sequence序列时，都会默认取出1000个序列缓存到本地。只有在它们用完之后，才会从数据库中获取接下来的1000个序列。按理说我们的压测QPS只有300左右，所以不应该和任何数据库交互那么频繁。然而，在与Arthas多次核实后，发现大部分CPU都在这里耗尽了。于是开始排查代码问题。最后发现一个傻问题，就是我们的序列创建和使用有问题：publicLonginsert(TdataObject){if(dataObject.getId()==null){Longid=next();dataObject.setId(id);}if(sqlSession.insert(getNamespace()+".insert",dataObject)>0){returndataObject.getId();}else{returnull;}}publicSequencesequence(){returnSequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build();}/***获取下一个主键ID**@return*/protectedLongnext(){try{returnsequence().nextValue();}catch(SequenceExceptione){thrownewRuntimeException(e);}}是因为我们每次插入一条语句都会重建一个新的序列，导致本地缓存丢失，所以每次都会去数据库拉取1000个新的，但是只用了一个。下次再取1000块，又开始循环。因此，对代码进行了调整，将Sequence实例的生成改为在应用启动时初始化一次。这样后面在获取序列的时候，就不会每次都去和数据库交互，而是先去查询本地缓存，等本地缓存耗尽后再去和数据库交互，获取新的序列。publicabstractclassBaseMybatisDAOimplementsInitializingBean{@OverridepublicvoidafterPropertiesSet()throwsException{sequence=SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build();}}通过实现InitializingBean，并重写afterPropertiesSet()方法，在该方法中执行序列初始化。修改以上代码后，提交验证。从监控数据可以看出，经过优化后，数据库的读RT明显下降；序列写操作的QPS也有明显下降：于是我们开始了新一轮的压力测试，但是发现CPU占用率还是很高。QPS还是上不去，于是又用Arthas查看线程状态。我们发现了一个新的CPU密集型线程栈，主要是因为我们使用了一个联调工具，预发布时默认开启了TDDL收集（官方文档描述预发布时默认不开启TDDL收集，但是将实际收集）。本工具在日志打印过程中会进行脱敏，脱敏框架会调用谷歌的re2j进行正则表达式匹配。因为我的操作中有很多TDDL操作，所以默认收集了大量的TDDL日志并进行脱敏，确实很耗CPU。所以这个问题可以通过在pre-release中关闭DP对TDDL的收集来解决。总结与思考本文总结了一个排查线上CPU飙升问题的过程。其实这个问题不难，也挺傻的，但是这个排查过程还是值得学习的。其实我之前也检查过很多次CPU高的问题，这次也是按照老方法检查，不过一开始并没有发现什么大问题，只是觉得是正常现象流量的增加导致了更多的数据库操作。期间经过多次排查（通过Arthas查看序列内容，通过数据库查看最近插入数据的主键ID等），发现TDDL的初始化机制有问题顺序。解决了这个问题之后，本以为问题彻底解决了，但是最后遇到了DP收集TDDL日志，导致CPU飙升，最后再次解决，还是有明显的提升。所以，事出必有魔，故障排除是一个抽丝剥茧的过程。
