应用接探针除了安全问题,最担心的就是占用系统性能影响业务正常运转,今天分享一个实际案例告诉大家如何来降低探针的性能损耗。
下表为某用户的2条核心链路在200并发压测下的性能数据对比,可以看见在接入探针后性能损耗居高不下。
首先想到的排查方案是通过skywalking监控进行排查,对比应用在接入探针和未接入探针的情况下,性能表现的差异在哪,具体的的性能消耗在哪个中间件。
在对比skywalking监控的链路耗时,确实可以观察到未接入探针比接入探针和链路的RT高,但是不清楚是否存在客户环境问题或者skywallking上的链路有断裂的问题,信息并不全面无法准确定位。
在无其它有效信息时,尝试通过排除法定位具体影响性能的插件。具体做法是先整理链路用到的中间件,先移除所有中间件插件,再逐一增加单个中间件插件,不断的进行压测,观察哪个插件对性能的影响比较大。依靠这个方法定位成功到dubbo与logback两个插件,它们对性能影响比较大。
在压测测试的同时,我们在agent框架内增加了对中间件插件interceptor方法执行的耗时统计代码,这部分数据会统一输出到固定的日志文件中。此外我们开发了与之配套的性能日志分析程序,配合日志收集脚本,可以对整个链路的所有应用打印的性能数据进行分析,输出汇总出一份中间件interceptor的统计结果,这份结果可以直观的看到每个中间件的性能耗时占比。
统计结果样例:
性能收集代码展示:
agent产生性能损耗的终归原因是因为agent增强中间件代码后,会修改目标类的字节码,植入一些额外的逻辑,正是这些额外的逻辑带来了额外的耗时。切点越多植入的逻辑越多,整个链路的损耗就可能越高,所以尽可能的减少切点的数量一定会减少性能损耗。
按照这个思路,我们将前面排查出来耗时占比较高的logback中间件进行了重新设计。原先logback的实现有三个切点,分别负责:影子appender的注册、流量标识、日志隔离,经过重新设计后,优化为一个切点实现所有功能。
尽管中间件插件的增强逻辑不尽相同,但agent在植入到目标类的字节码都是统一的。他们都有统一入口,前置的运行逻辑都是同一套框架,实际运行时序图如下:
实际上有很多Interceptor的增强逻辑只有压测流量时才会执行,可这部分interceptor的执行全部需要经过前面从Messager到AdviceListener的一系列调用,这是完全没有必要并且会带来一定的性能损耗。这种无用调用可以在最前端做个判断,从开始就过滤掉,在达到效果的同时降低性能损耗。
为此我们对框架进行了改造,让类似这种interceptor能在最前端就把流量过滤掉,避免执行无意义的逻辑。同时在最前端增加了静默开关,静默开关可以一键禁用掉所有中间件增强逻辑的执行,一定程度上可以代替卸载操作。相比卸载来说它不会还原实际的字节码,也不会回收内存占用,但是会更加轻量级,响应更快,影响更小。
改造后的运行时序图:
对logback插件进行重新设计后产生了一定效果,但是从性能采集的数据来看,性能损耗占比最高的还是logback插件。经过反复斟酌发现logback本身已经没有在进一步优化的空间了,于是将目光转向了框架层面,最后将重点放在了优化CutoffInterceptor类型中断机制。
CutoffInterceptor是一个类似挡板的Interceptor,它可以中断源码本身的运行,并且支持对返回值替换。比如数据库隔离的实现,我们一般会实现一个CutoffInterceptor,在压测流量经过时返回影子数据库的connection代替业务connection,以实现数据的隔离。logback同样也是实现了一个CutoffInterceptor,在压测流量经过时返回影子的appender替换业务的appender实现日志隔离。
CutoffInterceptor内部的实现原理是通过异常机制实现的,在替换返回值时,实际上是抛出了一个异常由上层捕获,实现对源代码的中断。
众所周知,在java中通过抛出实现流程控制的效率其实是比较低的,我们内部测试验证也证实了这点,一个空逻辑的CutoffInterceptor和同样的一个空逻辑Interceptor的性能差距相差几十近百倍。恰好logback这种日志类型的中间件执行频率是非常高的,所以导致这块的性能损耗一直下不去。于是我们把CutoffInterceptor的中断机制进行了优化,抛出异常改为了先advice设置中断标记,再由上层判断去控制中断。
经过一系列的优化动作之后,两条核心链路的性能损耗都有了大幅度的提升,链路A性能损耗由48%下降至4%,链路B的性能损耗由35%下降至3.4%。