ERROR日志打印导致CPU满载

青旅半醒 2022-09-14 03:07 225阅读 0赞

# 描述 #

开发环境对一台测试节点进行压测时，由于参数配置错误导致请求没有业务处理直接报错。随即停止压测后登录测试机器排查日志，以外发现虽然已经没有请求到该节点，但应用依然在打印错误日志，并且看日志时间是在打印几分钟前请求的日志。

第一反应是异步打印的日志出现堆积，于是查看了该应用所在节点的物理资源，发现CPU已经满荷载，以及JVM触发了多次Full GC和OOM。

# 分析 #

## 复现 ##

该节点重启后，以50TPS的速率故意发起错误请求的压测，果然稳定复现CPU满载的问题，因此盲猜是因为CPU满载导致异步日志打印速率慢，生产速度高于消费速度而出现日志堆积的情况，最终内存耗尽触发Full GC和OOM。通过arthas打印CPU火焰图后，发现CPU资源的消耗主要分布在日志异步打印时Class类加载方面，火焰图如下：

[20210828-223120.svg][]

![image][]

## CPU满载原因 ##

到这里有点摸不到头脑，大量日志打印会消耗CPU资源能理解，但仅仅每秒50次的日志打印也能吃满CPU？以及为什么日志打印会在类加载上消耗如此多的CPU资源？火焰图中为什么会出现3个类加载执行步骤？为了清楚以上问题，通过远程Debug来翻看该场景下日志打印的源代码实现。

通过层层debug，发现问题的核心代码逻辑在`org.apache.logging.log4j.core.impl.ThrowableProxy#loadClass(java.lang.ClassLoader, java.lang.String)`这个方法中。但打印ERROR日志的异常堆栈时，会尝试加载该异常堆栈中所有的类，类加载的代码实现如下。例如一个异常堆栈有76层，则会对这76个异常堆栈的类进行类加载，但事实上由于应用是SofaArk应用，存在多个破坏双亲委任的类加载器，导致此处逻辑虽然最多会尝试3次类加载，但始终都是使用SofaArk的PluginClassLoader对Class类进行尝试加载。

因此如果异常堆栈中出现PluginClassLoader加载不到的类，就会出现CPU火焰图中类加载3次的情况。

private Class<?> loadClass(final ClassLoader lastLoader, final String className) { 
        Class<?> clazz;
        // lastLoader为异常堆栈中上一个成功加载的Class类的类加载器
        // 始终为SofaArk的PluginClassLoader
        if (lastLoader != null) { 
            try { 
                clazz = lastLoader.loadClass(className);
                if (clazz != null) { 
                    return clazz;
                }
            } catch (final Throwable ignore) { 
                // Ignore exception.
            }
        }
        try { 
            // 实际使用Class.forName(className)
            // 通过LoaderUtil的classloader加载类,始终为SofaArk的PluginClassLoader
            clazz = LoaderUtil.loadClass(className);
        } catch (final ClassNotFoundException | NoClassDefFoundError e) { 
            return loadClass(className);
        } catch (final SecurityException e) { 
            return null;
        }
        return clazz;
    }
    
    private Class<?> loadClass(final String className) { 
        try { 
            // 使用ThrowableProxy的classloader加载类,始终为SofaArk的PluginClassLoader
            return Loader.loadClass(className, this.getClass().getClassLoader());
        } catch (final ClassNotFoundException | NoClassDefFoundError | SecurityException e) { 
            return null;
        }
    }

那么问题来了，为什么三次类加载都是用的PluginClassLoader尝试加载Class类？有哪些类是PluginClassLoader类加载器加载不到的？这里就涉及到[SofaArk的类加载机制][SofaArk]了，SofaArk中有两种类加载器：PluginClassLoader和BizClassLoader，前者加载不到Ark业务的类，后者加载不到Ark插件的类。

而SofaArk为了提供模块瘦身的能力，提前将大量的常用依赖jar包已经加载到SofaArk中，jar包列表见[plugin管控的依赖明细][plugin]，开发者就不需要再将这些依赖包再打包到运行jar包中，从而显著降低了运行包的体积。但这个功能导致了另外的一个问题：这些依赖jar包会优先由PluginClassLoader加载。其中就包括了log4j相关依赖，因此log4j的类加载器是PluginClassLoader，所以上述三次类加载过程中，始终都是通过PluginClassLoader尝试加载Class类。最终导致当一个异常堆栈打印时，其中的业务代码的类和其他未被SofaArk管控依赖的类会出现PluginClassLoader加载失败的问题。

![image][image 1]

protected Class<?> loadClassInternal(String name, boolean resolve) throws ArkLoaderException { 
        Class<?> clazz = null;
    
        // 0. sun reflect related class throw exception directly
      	// 如果是加载反射生成的字节码,直接抛出ClassNotFoundException,终止类加载
        if (classloaderService.isSunReflectClass(name)) { 
            throw new ArkLoaderException(
                String
                    .format(
                        "[ArkPlugin Loader] %s : can not load class: %s, this class can only be loaded by sun.reflect.DelegatingClassLoader",
                        pluginName, name));
        }
    
        // 1. findLoadedClass
        // 查找已经被加载过的类
        if (clazz == null) { 
            clazz = findLoadedClass(name);
        }
    
        // 2. JDK related class
        // 查找JDK中的类:ExtClassloader负责加载的类和SystemClassloader的classpath中的类
        if (clazz == null) { 
            clazz = resolveJDKClass(name);
        }
    
        // 3. Ark Spi class
        // SofaArk自身提供的接口类
        if (clazz == null) { 
            clazz = resolveArkClass(name);
        }
    
        // 4. pre find class
        if (clazz == null) { 
            clazz = preLoadClass(name);
        }
    
        // 5. Import class export by other plugins
        // 看是否在插件的import中,如果在则会委托给导出该类的插件类加载器加载
        if (clazz == null) { 
            clazz = resolveExportClass(name);
        }
    
        // 6. Plugin classpath class
        // 在插件自身的classpath中加载,此处CPU资源消耗严重
        if (clazz == null) { 
            clazz = resolveLocalClass(name);
        }
    
        // 7. Java Agent ClassLoader for agent problem
        // 查找Java Agent中的类
        if (clazz == null) { 
            clazz = resolveJavaAgentClass(name);
        }
    
        // 8. Post find class
        if (clazz == null) { 
            clazz = postLoadClass(name);
        }
    
        if (clazz != null) { 
            if (resolve) { 
                super.resolveClass(clazz);
            }
            return clazz;
        }
    
        throw new ArkLoaderException(String.format(
            "[ArkPlugin Loader] %s : can not load class: %s", pluginName, name));
    }

继续翻找日志打印源码发现，log4j之所以对异常堆栈中每一个类尝试类加载，实际上是为了获取该类所在的jar包名称和版本号，用于日志打印。而对于类加载失败时，则jar包名称和版本号均以`?`表示，最终输出的异常堆栈日志格式如下：

2021-08-28 21:57:40,066 [1e27b8881630159060131102218916 0.1 - /// - ] ERROR template.IcontentcenterServiceTemplate - facade service [ContentManageFacadeImpl.queryContentByIds] biz handle exception:QueryContentParam.idList contentId idList can not be empty
    com.alibaba.fastvalidator.constraints.exception.FastValidatorException: QueryContentParam.idList contentId idList can not be empty
    	at com.alibaba.fastvalidator.core.helper.FastValidatorHelper.throwFastValidateException(FastValidatorHelper.java:28) ~[?:?]
    	at com.alibaba.fastvalidator.core.FastValidatorUtils.validateUnQuite(FastValidatorUtils.java:96) ~[?:?]
    	at com.alipay.icontentcenter.biz.service.impl.content.ContentManageFacadeImpl$3.validate(ContentManageFacadeImpl.java:118) ~[?:?]
    	at com.alipay.icontentcenter.biz.shared.template.IcontentcenterServiceTemplate.execute(IcontentcenterServiceTemplate.java:72) ~[?:?]
    	at sun.reflect.GeneratedMethodAccessor181.invoke(Unknown Source) ~[?:?]
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
    	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
    	at com.alipay.sofa.runtime.service.binding.JvmBindingAdapter$JvmServiceInvoker.doInvoke(JvmBindingAdapter.java:253) ~[runtime-sofa-boot-3.4.6.jar!/:3.4.6]
    	at com.alipay.sofa.runtime.spi.service.ServiceProxy.invoke(ServiceProxy.java:40) ~[runtime-sofa-boot-3.4.6.jar!/:3.4.6]
    	at com.alipay.sofa.runtime.service.binding.JvmBindingAdapter$JvmServiceInvoker.invoke(JvmBindingAdapter.java:158) ~[runtime-sofa-boot-3.4.6.jar!/:3.4.6]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at com.alipay.icontentcenter.biz.shared.template.IcontentcenterServiceTemplate$$EnhancerBySpringCGLIB$$172e142b.execute(<generated>) ~[?:?]
    	at com.alipay.icontentcenter.biz.service.impl.content.ContentManageFacadeImpl.queryContentByIds(ContentManageFacadeImpl.java:105) ~[?:?]
    	at com.alipay.icontentcenter.biz.service.impl.content.ContentManageFacadeImpl$$FastClassBySpringCGLIB$$8bbedddb.invoke(<generated>) ~[?:?]
    	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at com.alicp.jetcache.anno.aop.JetCacheInterceptor.invoke(JetCacheInterceptor.java:42) ~[?:?]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at com.alicp.jetcache.anno.aop.JetCacheInterceptor.invoke(JetCacheInterceptor.java:42) ~[?:?]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at com.alipay.icontentcenter.biz.service.aop.FacadeLogAopAdvice.aroundAdvice(FacadeLogAopAdvice.java:66) ~[?:?]
    	at sun.reflect.GeneratedMethodAccessor180.invoke(Unknown Source) ~[?:?]
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
    	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
    	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
    	at com.alipay.icontentcenter.biz.service.impl.content.ContentManageFacadeImpl$$EnhancerBySpringCGLIB$$4269c5a.queryContentByIds(<generated>) ~[?:?]
    	at sun.reflect.GeneratedMethodAccessor179.invoke(Unknown Source) ~[?:?]
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
    	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
    	at com.alipay.sofa.rpc.filter.ProviderInvoker.invoke(ProviderInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.guardian.client.sofalite.RpcFilterMethodInvocation.proceed(RpcFilterMethodInvocation.java:76) ~[guardian-sofalite-1.4.15.jar!/:?]
    	at com.alipay.guardian.client.sofalite.GuardianFilterWrapper.invoke(GuardianFilterWrapper.java:53) ~[guardian-sofalite-1.4.15.jar!/:?]
    	at com.alipay.guardian.client.sofalite.GuardianRpcFilter.invoke(GuardianRpcFilter.java:58) ~[guardian-sofalite-1.4.15.jar!/:?]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.PressureMarkTransformFilter.invoke(PressureMarkTransformFilter.java:68) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.servcegovern.circuitbreaker.CircuitBreakerFilter.invoke(CircuitBreakerFilter.java:120) ~[sofa-rpc-enterprise-all-5.8.5.jar!/:5.8.5]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.servcegovern.faultinject.FaultInjectFilter.invoke(FaultInjectFilter.java:95) ~[sofa-rpc-enterprise-all-5.8.5.jar!/:5.8.5]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.ldc.filter.ProviderCustomFilter.invoke(ProviderCustomFilter.java:66) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.IpTransmitFilter.invoke(IpTransmitFilter.java:101) ~[sofa-rpc-enterprise-all-5.8.5.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.ldc.filter.ProviderAmbushFilter.invoke(ProviderAmbushFilter.java:46) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.ldc.elastic.processor.DirectRpcProcessor.process(DirectRpcProcessor.java:36) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.ldc.filter.ProviderElasticFilter.invoke(ProviderElasticFilter.java:136) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.ProviderProfileFilter.invoke(ProviderProfileFilter.java:67) ~[sofa-rpc-enterprise-all-5.8.5.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.sofatracer.ProviderTracerFilter.invoke(ProviderTracerFilter.java:74) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.ProviderBaggageFilter.invoke(ProviderBaggageFilter.java:45) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.RpcServiceContextFilter.invoke(RpcServiceContextFilter.java:62) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.ProviderExceptionFilter.invoke(ProviderExceptionFilter.java:37) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterInvoker.invoke(FilterInvoker.java:100) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.filter.FilterChain.invoke(FilterChain.java:268) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.server.ProviderProxyInvoker.invoke(ProviderProxyInvoker.java:65) ~[sofa-rpc-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.server.bolt.AlipayBoltProcessor.doInvoke(AlipayBoltProcessor.java:244) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.server.bolt.AlipayBoltProcessor.handleRequest(AlipayBoltProcessor.java:173) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.sofa.rpc.server.bolt.AlipayBoltProcessor.handleRequest(AlipayBoltProcessor.java:70) ~[sofa-rpc-alipay-all-5.7.6.jar!/:5.7.6]
    	at com.alipay.remoting.rpc.tr.protocol.TrRequestProcessor.doProcess(TrRequestProcessor.java:132) ~[bolt-tr-adapter-1.5.6.jar!/:?]
    	at com.alipay.remoting.rpc.tr.protocol.TrRequestProcessor$ProcessTask.run(TrRequestProcessor.java:306) ~[bolt-tr-adapter-1.5.6.jar!/:?]
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
    	at java.lang.Thread.run(Thread.java:858) [?:1.8.0_232]

通过jar包名称和版本号均为`?`判断该类为3次类加载失败的情况，数一下发现该异常堆栈中有13个类加载失败，该场景下一次异常堆栈打印需要执行39次类加载过程。因此复现步骤中虽然是以50TPS的低频率进行请求，但实际上导致了每秒近2000次的类加载。而复现步骤中抛出异常的位置是业务代码入口，因此涉及到的Ark业务类较少，试想一下，如果异常从比较深的路径上抛，一次请求中多次打印的异常堆栈，那么甚至可能出现每秒十几次甚至几次的持续错误请求就足够将该应用的CPU打垮而发生线上事故。

# 解决 #

通过分析得知，异常堆栈打印之所以导致CPU满载，是因为SofaArk应用多个ClassLoader实现的类隔离和瘦身能力导致异常堆栈日志打印时频繁执行无效的类加载过程，而通过CPU火焰图发现PluginClassLoader的`resolveLocalClass`方法对CPU资源消耗严重。

分析出问题引起的导火索是日志打印异常堆栈时输出jar包名称和版本号，因此盲猜涉及到了日志的输出格式。应用中使用的还是log4j作为日志输出工具，因此翻找log4j的[日志格式文档][Link 1]。文档中详细记录了异常堆栈的三种输出格式：

然后查看应用的日志输出配置，发现部分日志的输出格式没有表明异常堆栈的输出格式，如下：

通过log4j源码`org.apache.logging.log4j.core.pattern.PatternParser#parse(java.lang.String, boolean, boolean, boolean)`可得，异常堆栈的默认输出格式为`xEx|xException|xThrowable`。即未配置异常输出格式时，默认会通过类加载获取异常堆栈中每个类的包名和版本号。

for (final PatternConverter converter : converters) { 
        if (converter instanceof NanoTimePatternConverter) { 
            // LOG4J2-1074 Switch to actual clock if nanosecond timestamps are required in config.
            // LOG4J2-1248 set config nanoclock
            if (config != null) { 
                config.setNanoClock(new SystemNanoClock());
            }
        }
        LogEventPatternConverter pc;
        if (converter instanceof LogEventPatternConverter) { 
            pc = (LogEventPatternConverter) converter;
            handlesThrowable |= pc.handlesThrowable();
        } else { 
            pc = new LiteralPatternConverter(config, Strings.EMPTY, true);
        }
    
        FormattingInfo field;
        if (fieldIter.hasNext()) { 
            field = fieldIter.next();
        } else { 
            field = FormattingInfo.getDefault();
        }
        list.add(new PatternFormatter(pc, field));
    }
    // 当未配置异常输出格式时,默认使用ExtendedThrowablePatternConverter(xEx|xException|xThrowable格式)
    if (alwaysWriteExceptions && !handlesThrowable) { 
        final LogEventPatternConverter pc = ExtendedThrowablePatternConverter.newInstance(config, null);
        list.add(new PatternFormatter(pc, FormattingInfo.getDefault()));
    }

因此解决方案就很简单了，修改log4j的日志配置，强制指定每个日志文件的异常堆栈格式为`ex|exception|throwable`，修改如下：

<PatternLayout pattern="%d [%X{traceId} %X{rpcId} - %X{loginUserEmail}/%X{loginUserID}/%X{remoteAddr}/%X{clientId} - %X{requestURIWithQueryString}] %-5p %c{2} - %m%n" charset="UTF-8"/>
    
    
    <PatternLayout pattern="%d [%X{traceId} %X{rpcId} - %X{loginUserEmail}/%X{loginUserID}/%X{remoteAddr}/%X{clientId} - %X{requestURIWithQueryString}] %-5p %c{2} - %m%n%throwable" charset="UTF-8"/>

修改后，再对应用以50TPS的频率进行压测，CPU资源满载的问题已经解决，其CPU火焰图输出如下：

[20210828-221547.svg][]

![image][image 2]

[20210828-223120.svg]: https://img.wakzz.cn/202108/X3TAFG3WBB.svg
[image]: /images/20220828/0acfea8d8664454bac8536915a2c3282.png
[SofaArk]: https://www.sofastack.tech/projects/sofa-boot/sofa-ark-classloader/
[plugin]: https://yuque.antfin.com/middleware/arkserverless/uayrsm#fLKlN
[image 1]: /images/20220828/90cec093e7504943bdf2c317ba84a8c4.png
[Link 1]: http://logging.apache.org/log4j/2.x/manual/layouts.html
[20210828-221547.svg]: https://img.wakzz.cn/202108/QYT7d3WXJN.svg
[image 2]: /images/20220828/94aeed2f6a174b34a03e33e7905d4869.png