最近，业务增长的很迅猛，对于我们后台这块也是一个不小的挑战，这次遇到的核心业务接口的性能瓶颈，并不是单独的一个问题导致的，而是几个问题揉在一起：我们解决一个之后，发上线，之后发现还有另一个的性能瓶颈问题。这也是我经验不足，导致没能一下子定位解决；而我又对我们后台整个团队有着固执的自尊，不想通过大量水平扩容这种方式挺过压力高峰，导致线上连续几晚都出现了不同程度的问题，肯定对于我们的业务增长是有影响的。这也是我不成熟和要反思的地方。这系列文章主要记录下我们针对这次业务增长，对于我们后台微服务系统做的通用技术优化，针对业务流程和缓存的优化由于只适用于我们的业务，这里就不再赘述了。本系列会分为如下几篇：

改进客户端负载均衡算法
开发日志输出异常堆栈的过滤插件
针对 x86 云环境改进异步日志等待策略
增加对于同步微服务的 HTTP 请求等待队列的监控以及云上部署，需要小心达到实例网络流量上限导致的请求响应缓慢
针对系统关键业务增加必要的侵入式监控

开发日志输出异常堆栈的过滤插件

我们一般会在异常发生时，打印日志，同时日志中带有异常堆栈。

在线上因为某个基础组件或者某个存储慢导致大量超时异常发生时，如果都打印完整的异常栈，则一下子会输出大量的日志，导致写入日志也会成为瓶颈（虽然我们使用了 Log4j2 的异步日志，但是如果 RingBuffer 满了输出日志还是会导致业务线程阻塞）。从而导致同一微服务中其他本来正常的业务，也变得不正常了。

并且，我们发现

为何 JVM 参数中加入 -XX:-OmitStackTraceInFastThrow

为了避免这个问题可能首先想到的是，JVM 参数中去掉 -XX:-OmitStackTraceInFastThrow。这个 OmitStackTraceInFastThrow 默认是启用的，其作用是，当某个 JDK 内置异常通过某一个方法抛出过多次数时（常见是 NullPointerException），自动省略异常堆栈，其实就是 Throwable.getOurStacktrace() 返回空数组。底层实现的方式是当这些异常被抛出时，会记录在方法的 method_data 中。当这些异常被抛出时，检查对应方法的 method_data 是否有过多次数的这些异常被抛出，如果有，则使用不含堆栈的异常对象替换原有异常对象从而实现异常堆栈被忽略。对应源码：

graphKit.cpp

  bool treat_throw_as_hot = false;ciMethodData* md = method()->method_data();if (ProfileTraps) {//如果有太多次，则 treat_throw_as_hot 为 trueif (too_many_traps(reason)) {treat_throw_as_hot = true;}if (C->trap_count(reason) != 0&& method()->method_data()->trap_count(reason) != 0&& has_ex_handler()) {treat_throw_as_hot = true;}}if (treat_throw_as_hot&& (!StackTraceInThrowable || OmitStackTraceInFastThrow)) {ciInstance* ex_obj = NULL;switch (reason) {case Deoptimization::Reason_null_check://对于 NullPointerException 返回对应的空堆栈的内置 NullPointerException 对象ex_obj = env()->NullPointerException_instance();break;case Deoptimization::Reason_div0_check://对于 ArithmeticException 返回对应的空堆栈的内置 ArithmeticException 对象ex_obj = env()->ArithmeticException_instance();break;case Deoptimization::Reason_range_check://对于 ArrayIndexOutOfBounds 返回对应的空堆栈的内置 NullPoArrayIndexOutOfBoundsinterException 对象ex_obj = env()->ArrayIndexOutOfBoundsException_instance();break;case Deoptimization::Reason_class_check:if (java_bc() == Bytecodes::_aastore) {//对于 ArrayStoreException 返回对应的空堆栈的内置 ArrayStoreException 对象ex_obj = env()->ArrayStoreException_instance();} else {//对于 ClassCastException 返回对应的空堆栈的内置 ClassCastException 对象ex_obj = env()->ClassCastException_instance();}break;default:break;}

但是，我们一般会在 JVM 启动参数中加入 -XX:-OmitStackTraceInFastThrow 将其关闭，主要原因是：

OmitStackTraceInFastThrow 这个参数仅针对某些 Java 内置异常（上面源码已经列出），对于我们自定义或者框架自定义的异常没用。
分析是否过多，仅对于抛出异常的方法，但是是否是同一调用路径，并没有考虑。
微服务线程可能会运行很长时间，我们业务日志量非常大，每一个小时产生一个新文件。假设某个方法每天抛出一定量的 NullPointerException 但是不多，并没有及时发现。日积月累，某一天突然就没有堆栈了。之后如果这个方法大量抛出 NullPointerException，我们却看不到堆栈，还得去挨个翻之前的日志，这样太低效率了。

我们对于异常日志的需求

由于我们项目中使用了各种框架，有的使用了异步框架，导致异常栈会非常非常长（有的甚至有 1000 行），所以其实最符合我们需求的是：

每次异常都输出异常栈
但是异常栈只包括我们关心的包，其他的包都被省略，防止异常栈过长导致输出大量日志。

Log4j2 官方关于异常的配置

Log4j2 官方只是提供了黑名单包的配置，也就是哪些包的异常栈被省略掉；还有关于精简异常栈的就是输出日志的前几行，但是我们无法保证我们关心的日志一定位于日志的前几行，尤其是针对异步响应式代码调用的异常栈的时候。

不过 Log4j2 的这些配置，是通过 Pattern 插件的方式实现的，我们也可以通过开发自定义的 Pattern 插件实现。

开发自定义 Pattern 插件

首先，Log4j2 官方只是提供了黑名单包的配置，我们可以将黑名单包的配置的判断逻辑取反，其实就变成了白名单，其他的配置格式解析照旧。于是我们将 Log4j2 的代码 ThrowableProxyRenderer 复制出来，命名为我们自定义的 CustomizedThrowableProxyRenderer，同时将其中 package-private 的方法改成 public 的，这样我们可以在任何地方调用。并且将其中黑名单判断取反，改成白名单：

完整源码参考：https://github.com/JoJoTec/spring-cloud-parent/blob/master/spring-cloud-commons/src/main/java/org/apache/logging/log4j/core/impl/CustomizedThrowableProxyRenderer.java

public class CustomizedThrowableProxyRenderer {//省略没有修改的方法//该方法改为 publicpublic static void formatExtendedStackTraceTo(final ThrowableProxy src, final StringBuilder sb, final List<String> whiteListedPackages, final TextRenderer textRenderer, final String suffix, final String lineSeparator) {textRenderer.render(src.getName(), sb, "Name");textRenderer.render(": ", sb, "NameMessageSeparator");textRenderer.render(src.getMessage(), sb, "Message");renderSuffix(suffix, sb, textRenderer);textRenderer.render(lineSeparator, sb, "Text");final StackTraceElement[] causedTrace = src.getThrowable() != null ? src.getThrowable().getStackTrace() : null;formatElements(sb, Strings.EMPTY, 0, causedTrace, src.getExtendedStackTrace(), whiteListedPackages, textRenderer, suffix, lineSeparator);formatSuppressed(sb, TAB, src.getSuppressedProxies(), whiteListedPackages, textRenderer, suffix, lineSeparator);formatCause(sb, Strings.EMPTY, src.getCauseProxy(), whiteListedPackages, textRenderer, suffix, lineSeparator);}//原来的 blackListElement 方法改成 whiteListedElement//结果取反，改成白名单private static boolean whiteListedElement(final StackTraceElement element, final List<String> whiteListedPackages) {if (whiteListedPackages != null) {final String className = element.getClassName();for (final String pkg : whiteListedPackages) {if (className.startsWith(pkg)) {return true;}}}return false;}
}

然后，开发我们自定义的 Log4j2 Pattern 插件：

CustomizedThrowablePatternConverter.java

@Plugin(name = "CustomizedThrowablePatternConverter", category = PatternConverter.CATEGORY)
@ConverterKeys({ "cusEx", "cusThrowable", "cusException" })
public class CustomizedThrowablePatternConverter extends ThrowablePatternConverter {public static CustomizedThrowablePatternConverter newInstance(final Configuration config, final String[] options) {return new CustomizedThrowablePatternConverter(config, options);}private CustomizedThrowablePatternConverter(final Configuration config, final String[] options) {super("CustomizedThrowable", "throwable", options, config);}@Overridepublic void format(final LogEvent event, final StringBuilder toAppendTo) {final ThrowableProxy proxy = event.getThrownProxy();final Throwable throwable = event.getThrown();if ((throwable != null || proxy != null) && options.anyLines()) {if (proxy == null) {super.format(event, toAppendTo);return;}final int len = toAppendTo.length();if (len > 0 && !Character.isWhitespace(toAppendTo.charAt(len - 1))) {toAppendTo.append(' ');}//调用上面的工具类，格式化异常CustomizedThrowableProxyRenderer.formatExtendedStackTraceTo(proxy, toAppendTo, options.getIgnorePackages(),options.getTextRenderer(), getSuffix(event), options.getSeparator());}}
}

这样，我们可以在我们的 Log4j2 配置中，加入这个异常定义 PatternLayout，例如：

<RollingFile name="file" append="true"filePattern="${LOG_ROOT}/app.log-%d{yyyy.MM.dd.HH}-${sys:LOCAL_IP}"><PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %5p [%X{traceId},%X{spanId}] [${sys:PID}] [%t]: %m%n%cusEx{filters(java, com.mycompany)}"/><Policies><TimeBasedTriggeringPolicy interval="1" modulate="true"/></Policies><DirectWriteRolloverStrategy maxFiles="72"/>
</RollingFile>

其中的 %cusEx{filters(java, com.mycompany)}，代表异常栈就只会输出这些包开头的异常堆栈，这里是 java 和 com.mycompany 开头的。如此一来，log.error("something error!", e);，输出的日志就会类似于：

2021-10-30 16:00:19.254  ERROR [65f6eda3bf6a48ee,d25cc4c9eb1deed6] [30] [subscribe-pool-9]: something error!... suppressed 27 linesat com.mycompany.spring.cloud.parent.web.common.undertow.jfr.JFRTracingFilter.doFilter(JFRTracingFilter.java:40) ~[spring-cloud-parent-web-common-2020.0.3-SNAPSHOT.jar!/:2020.0.3-SNAPSHOT]at com.mycompany.spring.cloud.parent.web.common.undertow.jfr.LazyJFRTracingFilter.doFilter(LazyJFRTracingFilter.java:23) ~[spring-cloud-parent-web-common-2020.0.3-SNAPSHOT.jar!/:2020.0.3-SNAPSHOT]... suppressed 46 lines
Caused by: com.alibaba.fastjson.JSONException: write javaBean error, fastjson version 1.2.75, class com.hopegaming.factsCenter.query.revo.controller.frontend.share.matches.MatchController$EventVO, fieldName : data... suppressed 8 lines... 74 more
Caused by: java.lang.NullPointerExceptionat com.mycompany.OrderController.postOrder(OrderController.java:103) ~[classes!/:2020.0.3-SNAPSHOT]... suppressed 13 lines... 74 more

微信搜索“我的编程喵”关注公众号，每日一刷，轻松提升技术，斩获各种offer：

近期业务大量突增微服务性能优化总结-2.开发日志输出异常堆栈的过滤插件相关推荐

并发+JVM+Redis+MySQL+分布式+微服务+性能优化及阿里等大厂最新面试问答！
不知道有多少人和我一样是年前辞职,结果赶上了疫情,在家里一呆就是几个月! 但塞翁失马,焉知非福!我本来就打算年后找工作,正好趁着这段时间,找一些在大厂的朋友们收集了阿里.腾讯.字节跳动.百度.华为.美 ...
Java微服务性能优化
最近在做微服务的性能优化,下面是对这次优化中,采用的方法和调整策略: 使用JMeter进行接口压测使用JProfiler对压测过程中进行记录,分析接口耗时,内存等通过jvm命令,分析内存使用使用 ...
华为云高级测试专家马海谈《云时代如何更高效测试微服务性能》
马海:大家好,我叫马海,来自于杭州华为研究所,我目前任职于华为云cloudBU,主要负责云性能测试服务CPTS的开发与测试工作.非常荣幸今天能够来到北京参加这次的云测峰会,也很高兴能和这么多同行一起共 ...
工业微服务——实现工业APP高效开发和运行
工业微服务架构为工业互联网平台的知识转化和复用提供了最佳技术手段,算法.模型.知识等模块化组件能够以"搭积木"的方式被调用和编排,实现低门槛.高效率的工业App开发. 微服务最早由 ...
业务系统性能问题分析诊断和性能优化怎么做？
- 前言 - 今天谈下业务系统性能问题分析诊断和性能优化方面的内容.这篇文章重点还是谈已经上线的业务系统后续出现性能问题后的问题诊断和优化重点. 系统性能问题分析流程我们首先来分析下如 ...
[微服务/API时代的前端开发] BFF入门--5个实用的BFF使用案例
5个实用的BFF使用案例前言 API Gateway 服务器端渲染(Server Side Rendering) 会话管理(Session Management) 上传文件 WebSocket.Se ...
[微服务/API时代的前端开发] BFF超入门--Netflix、Twitter、Recruit选择BFF的理由
前言在本系列"微服务/API时代的前端开发"中,我们将介绍当前备受关注的BFF(Backends For Frontends).这一篇,我们将主要介绍BFF的概要和例子,作为&q ...
由美团技术文章整理---spark性能优化基础篇--开发调优与资源参数调优
文章地址1:Spark性能优化指南--基础篇 - 美团技术团队文章地址2:Spark性能优化指南--高级篇 - 美团技术团队目录一.关于性能优化基础篇--开发调优 1.避免创建重复RDD (1) ...
在低容错业务场景下落地微服务的实践经验
"健康体检是一个低容错的场景,用户到医院体检,由于 IT 原因导致无法完成预约的项目,会对用户体验造成极大的影响." --禾连健康 CTO 邓志豪禾连健康成立于 2014 年,是 ...

近期业务大量突增微服务性能优化总结-2.开发日志输出异常堆栈的过滤插件