此问题是在为客户的系统进行压测时发现的，为了降低性能风险，对其进行了分析和改进。分享此案例也希望能给同学们一些启发和提醒。

问题现象

压测过程中发现应用服务器CPU消耗较高

分析过程

首先根据链路/分析平台监控到的数据作出分析

问题1: 有没有哪个方法集中消耗了大量的CPU？

从XLand热点分析看到单单一个爬栈操作就占用了当前CPU使用率的30%左右

问题2: 是谁导致了爬栈操作？

从方法调用栈可以看出是logback日志组件中触发了爬栈操作

结合反编译工具或直接查看源码进行分析

问题3: 什么情况下logback会触发爬栈操作呢？

查看logback源码可以发现如下四个方法会触发爬栈操作：

如上四个方法都会调用如下方法进行爬栈操作

官方文档说明和建议

官方文档也说明这四种日志pattern参数会导致性能问题，不建议使用

转换符	作用
F / file	输出执行记录请求的java源文件名。尽量避免使用，除非执行速度不造成任何问题。
C {length } class {length }	输出执行记录请求的调用者的全限定名。参数与上面的一样。尽量避免使用，除非执行速度不造成任何问题。
M / method	输出执行日志请求的方法名。尽量避免使用，除非执行速度不造成任何问题。
L / line	输出执行日志请求的行号。尽量避免使用，除非执行速度不造成任何问题。

性能风险点

1.频繁爬栈会占用大量cpu

a)日志打印越频繁，爬栈操作也就越频繁
b)获取到方法栈后会有一个循环赋值的操作，方法栈越深，循环赋值次数就越多，单次爬栈消耗的cpu也就越多

2.频繁爬栈会影响响应时间

(1)爬栈会有一个短暂的STW（stop the world），会暂停应用线程的执行，所以在方法中打印日志越频繁，STW次数也就越多，对响应时间会有少量影响
(1)频繁爬栈会产生大量StackTraceElement[] 临时对象，进而导致更频繁的young gc，而young gc使用的是复制算法，也是会STW的。所以频繁的gc不仅会浪费更多的cpu在垃圾回收上，还会导致更多的应用线程暂停，从而影响到响应时间

优化建议

部分开发会在日志中输出行号或者方法名，是为了更快速的定位一些异常问题，而异常日志通常会被定义成ERROR或者WARN级别，所以建议将ERROR/WARN级别的日志和INFO/DEBUG级别的日志分别设置pattern，允许异常日志输出行号和方法名等信息，常规日志则不允许。