一个关于log4j2的高并发问题
原文连接：blog.fliaping.com/a-high-conc…html
前言
日志应该是一个应用的基础组件, 其中老牌的log4j应该是咱们用的最多的, 后来互联网发展,你们都朝着高并发的方向发力,发现log4j性能不行,由于竞争锁致使阻塞,性能跟不上. 后来其创始人另立门户logback后, log4j的新主子Apache进行了大的升级改造,就是现在的log4j2, 其异步日志的性能也是一骑绝尘, 然而其使用过程当中依然有不少坑,稍不留意就会搞我的仰马翻. 下面先列举一些别人踩过的log4j的坑:java
问题描述
初级表现
一个APP推送服务,在一次发布以后, 当遇到批量推送任务时, 线程池打满, 队列打满, 任务堆积. (注: 因为该次发布的改动点很普通, 没有先怀疑该点.)spring
相关环境
- spring-boot: 1.5.3
- log4j: 2.7
- jdk1.8
发布改动点
- 新增了一个功能 （和本次内容无关）
- 在一个类上加了
@RefreshScope注解
处理流程
- 原觉得是第三方接口耗时增长致使的, 监控显示耗时确实挺高,可是经过ping,curl,网络监控等手段发现并非接口问题
- 阅读代码发现那个监控项不只包含了调用第三方接口的耗时,还有其它操做, 遂认为该监控不可信,再次验证不是第三方接口,也不是网络的问题
- 发现统计日志中的两个时间点差别比较大,居然有三秒. 关键是这两个时间点之间只是抛了个异常,而后打了个日志
- 在代码中发现log4j2配置用的是同步Logger,异步AsyncAppender,怀疑是高并发时同步日志产生的阻塞, 将日志改成配合disrupter的AsyncLogger,结果没有什么用
- 进行Thread Dump发现不少线程BLOCKED,调用栈显示确实是与log4j有关, 而且明显指向和异常栈打印有关
- 因为应用中有不少警告, 而且这些日志都把异常栈打印出来了. 因而将日志中没必要要的异常栈都中止打印, 以后问题解决
问题分析
疑问点
- 日志为何没有走异步打印?
- 为何打印异常栈会阻塞? 阻塞在什么地方?
- 为何会引发阻塞,和发布的改动点有哪些联系?
线程栈分析
如下日志为改成异步日志(AsyncLogger)以后的阻塞线程栈,能够发现日志并无用到disruptor这个无锁库,而是转为了同步Loggerapache
"fastExecutor-670" #2178 prio=5 os_prio=0 tid=0x00007f2d483cd800 nid=0x6026 waiting for monitor entry [0x00007f2c158c3000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.ClassLoader.loadClass(ClassLoader.java:404)
- waiting to lock <0x0000000088104b60> (a java.lang.Object)
at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:94)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:539)
at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:660)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:137)
at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:94)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:539)
at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:660)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:137)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:121)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.getThrownProxy(Log4jLogEvent.java:555)
at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:61)
... 精简部分日志 ...
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:447)
at org.apache.logging.log4j.core.async.AsyncLoggerConfig.callAppendersInCurrentThread(AsyncLoggerConfig.java:105)
at org.apache.logging.log4j.core.async.EventRoute$2.logMessage(EventRoute.java:65)
at org.apache.logging.log4j.core.async.AsyncLoggerConfig.callAppenders(AsyncLoggerConfig.java:95)
at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:432)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:416)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:402)
at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1988)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1960)
at org.apache.logging.slf4j.Log4jLogger.warn(Log4jLogger.java:259)
at com.dianwoda.delibird.common.traffic.FastCommander.lambda$runnersEnter$0(FastCommander.java:175)
at com.dianwoda.delibird.common.traffic.FastCommander$$Lambda$111/638548222.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
复制代码
如下为应用异常栈内容bootstrap
com.dianwoda.delibird.common.domain.DeliException:
at com.dianwoda.delibird.push.manager.PushManager.send(PushManager.java:104) ~[classes!/:?]
at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_77]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_77]
at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:216) ~[spring-core-4.3.15.RELEASE.jar!/:4.3.15.RELEASE]
at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:472) ~[spring-cloud-context-1.3.3.RELEASE.jar!/:1.3.3.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.15.RELEASE.jar!/:4.3.15.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) ~[spring-aop-4.3.15.RELEASE.jar!/:4.3.15.RELEASE]
at com.dianwoda.delibird.push.manager.PushManager$$EnhancerBySpringCGLIB$$74851038.send(<generated>) ~[classes!/:?]
at com.dianwoda.delibird.push.provider.DeliPushProviderImpl.lambda$send$0(DeliPushProviderImpl.java:84) ~[classes!/:?]
at com.dianwoda.delibird.common.tool.DeliRunnable.run(DeliRunnable.java:26) ~[delibird-common-1.0-SNAPSHOT.jar!/:?]
at com.dianwoda.delibird.common.traffic.FastCommander.lambda$runnersEnter$0(FastCommander.java:173) ~[delibird-common-1.0-SNAPSHOT.jar!/:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_77]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_77]
at java.lang.Thread.run(Thread.java:745) [?:1.8.0_77]
复制代码
疑问点一
日志为何没有走异步打印?api
Log4j2中默认会优先尝试将LogEvent放入RingBuffer中，若是放不进去（缘由大概是队列已满），则会经过AsyncQueueFullPolicy（可自定义）来决策下一步行为（EventRoute：丢弃 - discard，同步 - synchronous，等待入队 - enqueue），在log4j-2.7中默认是同步写日志（2.9中默认是等待入队Enqueue的方式），所以，当日志量突增时，异步日志变同步日志！缓存
疑问点二
为何打印异常栈会阻塞? 阻塞在什么地方?网络
根据线程栈, 问题主要是由于org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace这个方法. 其中ThrowableProxy这个类是由于LogEvent可能会被跨网络传输，而LogEvent中的异常栈可能不会被另外一端识别，所以须要对异常栈进行从新封装，会取出栈中异常的jar包及版本等信息。该类的注释以下:多线程
包装一个Throwable并添加每一个堆栈跟踪元素的包信息。
用于在不一样ClassLoader或JVM中表示Throwable的一个代理,当应用反序列化一个ThrowableProxy, Throwable也许没有被设置,可是Throwable信息被保存在该代理的其它字段,像 message和stack trace并发
另外该方法是为了"解析此堆栈跟踪中与父元素不一样的全部堆栈条目", 简单的讲,就是把异常堆栈与当前的线程栈做对比,把异常堆栈中不同的类信息解析出来,包括类名,行号,包名,包版本等信息,这时候就须要根据异常栈中的类名获取Class对象,便须要类加载. 根据线程栈来分析下类加载的过程, 能够看到阻塞的地方是在等待一个锁, 正是由于锁等待致使打印日志的操做耗时3s.
如下为阻塞线程的线程栈:
at java.lang.ClassLoader.loadClass(ClassLoader.java:404)
- waiting to lock <0x0000000088104b60> (a java.lang.Object)
at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:94)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:539)
at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:660)
复制代码
如下为类加载获取锁的代码片断: code-1
// java.lang.ClassLoader#loadClass(java.lang.String, boolean)
protected Class<?> loadClass(String name, boolean resolve)
throws ClassNotFoundException
{
synchronized (getClassLoadingLock(name)) { // 源码行号:404
//(1. 注: 先从jvm检查下类加载过没有,已加载就直接返回该对象,防止类重复加载)
// First, check if the class has already been loaded
Class<?> c = findLoadedClass(name);
if (c == null) {
long t0 = System.nanoTime();
try {
// 2. 若是该类加载器有父对象,先用父加载器加载,这就是双亲委派机制
if (parent != null) {
c = parent.loadClass(name, false);
} else {
// 3. 若是父加载器加载不到,就用引导加载器加载
c = findBootstrapClassOrNull(name);
}
} catch (ClassNotFoundException e) {
// ClassNotFoundException thrown if class not found
// from the non-null parent class loader
}
if (c == null) {
// If still not found, then invoke findClass in order
// to find the class.
long t1 = System.nanoTime();
// 4. 若是前面双亲都没有加载到, 采用当前自定义的findClass加载
c = findClass(name); // 源码行号:424
// this is the defining class loader; record the stats
sun.misc.PerfCounter.getParentDelegationTime().addTime(t1 - t0);
sun.misc.PerfCounter.getFindClassTime().addElapsedTimeFrom(t1);
sun.misc.PerfCounter.getFindClasses().increment();
}
}
if (resolve) {
resolveClass(c);
}
return c;
}
}
复制代码
能够看到类加载的时候会先用检查下是否已经加载过,加载过就直接返回jvm中的类对象. 若是是走的是获取加载过的类,应该是很是快的,由于仅仅是一个内存操做,获取的锁会被立刻释放, 在几千QPS的状况下根本不可能发生阻塞3s这样的事情, 那么此时的类到底有没有被加载过呢?
能够看下获取到该锁 0x0000000088104b60 的线程栈:
"fastExecutor-671" #1739 prio=5 os_prio=0 tid=0x00007f2d00015000 nid=0x5e64 runnable [0x00007f2c237f9000]
java.lang.Thread.State: RUNNABLE
at sun.misc.URLClassPath$Loader.getResource(URLClassPath.java:702)
at sun.misc.URLClassPath.getResource(URLClassPath.java:212)
at java.net.URLClassLoader$1.run(URLClassLoader.java:365)
at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
- locked <0x0000000088104b60> (a java.lang.Object)
at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:94)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:539)
... 精简部份内容 ...
复制代码
根据上面的线程栈, 获取锁以后走到源码的424行, 就表示类没有在jvm中加载过,而且双亲加载器也加载不到,调用了findClass去加载. 这里就很是奇怪了, jvm若是加载过一次,下次必定会从jvm中直接拿到, 结合前面说的锁会立刻释放, 根本不会阻塞. 也就是说实际每次要从新加载. 为了找到具体是哪一个类每次都须要加载一次,须要来debug肯定.
下面是log4j2中 ThrowableProxy 类加载流程的代码: code-2 ,是调用类加载的地方.
// org.apache.logging.log4j.core.impl.ThrowableProxy#loadClass(java.lang.String)
/** * Loads classes not located via Reflection.getCallerClass. * * @param lastLoader The ClassLoader that loaded the Class that called this Class. * @param className The name of the Class. * @return The Class object for the Class or null if it could not be located. */
private Class<?> loadClass(final ClassLoader lastLoader, final String className) {
// XXX: this is overly complicated (注:确实过于复杂,哈哈哈)
Class<?> clazz;
if (lastLoader != null) {
try {
// 1. 先用ClassLoader加载一下, 加载上就返回
clazz = lastLoader.loadClass(className); // 源码行号: 539
if (clazz != null) {
return clazz;
}
} catch (final Throwable ignore) {
// Ignore exception.
}
}
try {
// 2. 上一步没加载上,或者出现异常,用LoaderUtil再次加载(使用Class.forName以及当前线程的ClassLoader)
clazz = LoaderUtil.loadClass(className);
} catch (final ClassNotFoundException | NoClassDefFoundError e) {
// 3. 加载出现异常,再次尝试一种加载方式
return loadClass(className);
} catch (final SecurityException e) {
return null;
}
return clazz;
}
// 4. 接上面的3, 再次用当前对象类的加载器加载,出现异常返回空
private Class<?> loadClass(final String className) {
try {
return this.getClass().getClassLoader().loadClass(className);
} catch (final ClassNotFoundException | NoClassDefFoundError | SecurityException e) {
return null;
}
}
复制代码
调试过程
先让代码跑起来,并走几回出问题的流程,确保该加载的类已经加载过了, 而后在 code-1 中 findLoadedClass 方法处打断点并查看返回值是否为空. code-2 中lastLoader的类型是LaunchedURLClassLoader 继承关系以下图
loadClass 方法如: code-3 : org.springframework.boot.loader.LaunchedURLClassLoader#loadClass
@Override
protected Class<?> loadClass(String name, boolean resolve)
throws ClassNotFoundException {
Handler.setUseFastConnectionExceptions(true);
try {
try {
definePackageIfNecessary(name);
}
catch (IllegalArgumentException ex) {
// Tolerate race condition due to being parallel capable
if (getPackage(name) == null) {
// This should never happen as the IllegalArgumentException indicates
// that the package has already been defined and, therefore,
// getPackage(name) should not return null.
throw new AssertionError("Package " + name + " has already been "
+ "defined but it could not be found");
}
}
return super.loadClass(name, resolve);
}
finally {
Handler.setUseFastConnectionExceptions(false);
}
}
复制代码
执行 lastLoader.loadClass(className) 跳到 code-1 , 整个加载流程遵循双亲委派机制, 以下图
LaunchedURLClassLoader是一个自定义类加载器, 直接调用父类 ClassLoader#loadClass 即 code-1 中所示, 分别用“应用类加载器”、“扩展类加载器”、“引导类加载器”加载，最终发现了当出现类名 sun.reflect.GeneratedMethodAccessor204 时通过 parent loaders、bootstrap loader、URLClassLoader#findClass都加载不到，最后抛出ClassNotFoundException被 code-2 步骤1处捕获并忽略，接着执行步骤2继续尝试加载，随后抛出异常，捕获后在步骤3处再次尝试加载，再次异常返回空。
如异常日志at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source) ~[?:?]， 因为加载不到该类，源码信息、包信息都是没有的。
插曲: 调试过程当中重启了一次应用，发现再也走不到以前的调试逻辑了，好像全部的事情都正常了，没有加载不上的类了，顿时一脸懵逼。而后误打误撞，用一个批量调用的脚本吭哧吭哧一顿调用，而后问题又重现了
在准备看看sun.reflect.GeneratedMethodAccessor204这个类为何加载不上时，发现根本没有这个类，一看类名就怀疑是反射生成的类。加上以前的插曲，另外还有别人的提醒，以及google，发现根本缘由竟是jvm对反射的优化策略。
jvm对反射的优化
jvm对待反射有两种方式：
- 使用native方法进行反射操做，这种方式每次执行的速度差很少
- 生成bytecode进行反射操做，即生成类
sun.reflect.GeneratedMethodAccessor<N>，它是一个被反射调用方法的包装类，代理不一样的方法，类后缀序号会递增。这种方式第一次调用速度较慢，较之第一种会慢3-4倍，可是屡次调用后速度会提高20倍
在ReflectionFactory里有一种机制，就是当一个方法被反射调用的次数超过必定的阀值时（inflationThreshold），会使用第二种方式来提高速度。这个阀值的默认值是15.该阈值能够经过jvm参数-Dsun.reflect.inflationThreshold进行配置。
那么为何log4j2不能加载到生成类sun.reflect.GeneratedMethodAccessor<N>呢？
要回答这个问题就要了解jvm反射实现的第二种方式,jvm会经过方法sun.reflect.ReflectionFactory#newMethodAccessor构建MethodAccessor，代理经过该对象的invoke方法调用真正的方法。下图为MethodAccessor接口的相关实现类
ReflectionFactory#newMethodAccessor代码以下: code-4
public MethodAccessor newMethodAccessor(Method method) {
checkInitted();
// noInflation(不膨胀)，直接使用字节码加强方式
if (noInflation && !ReflectUtil.isVMAnonymousClass(method.getDeclaringClass())) {
return new MethodAccessorGenerator().
generateMethod(method.getDeclaringClass(),
method.getName(),
method.getParameterTypes(),
method.getReturnType(),
method.getExceptionTypes(),
method.getModifiers());
} else {
// 不然使用Inflation膨胀模式， 先建立NativeMethodAccessorImpl，随后将该实现做为DelegatingMethodAccessorImpl的一个delegate，实际上仍是委派给NativeMethodAccessorImpl
NativeMethodAccessorImpl acc =
new NativeMethodAccessorImpl(method);
DelegatingMethodAccessorImpl res =
new DelegatingMethodAccessorImpl(acc);
acc.setParent(res);
return res;
}
}
复制代码
sun.reflect.NativeMethodAccessorImpl#invoke代码以下： code-5
public Object invoke(Object obj, Object[] args) throws IllegalArgumentException, InvocationTargetException {
// We can't inflate methods belonging to vm-anonymous classes because
// that kind of class can't be referred to by name, hence can't be
// found from the generated bytecode.(咱们不能膨胀属于vm-anonymous的类，由于这种类不能经过名字引用，所以不能从生成的字节码中被发现)
//
// 这里能够看到，若是调用次数大于inflationThreshold就会膨胀，使用字节码加强的方式
if (++numInvocations > ReflectionFactory.inflationThreshold()
&& !ReflectUtil.isVMAnonymousClass(method.getDeclaringClass())) {
MethodAccessorImpl acc = (MethodAccessorImpl)
new MethodAccessorGenerator().
generateMethod(method.getDeclaringClass(),
method.getName(),
method.getParameterTypes(),
method.getReturnType(),
method.getExceptionTypes(),
method.getModifiers());
parent.setDelegate(acc);
}
// 没有超过膨胀阈值，就使用JNI方法
return invoke0(method, obj, args);
}
复制代码
继续查看代码，能够看到sun.reflect.MethodAccessorGenerator#generate的实现是调用asm字节码加强工具来生成类，此过程较长，不在此列出。在该方法的最后，咱们发现有这样一个操做sun.reflect.ClassDefiner#defineClass，查看其源码
defineClass代码以下： code-6
/** <P> We define generated code into a new class loader which delegates to the defining loader of the target class. It is necessary for the VM to be able to resolve references to the target class from the generated bytecodes, which could not occur if the generated code was loaded into the bootstrap class loader. </P> <P> There are two primary reasons for creating a new loader instead of defining these bytecodes directly into the defining loader of the target class: first, it avoids any possible security risk of having these bytecodes in the same loader. Second, it allows the generated bytecodes to be unloaded earlier than would otherwise be possible, decreasing run-time footprint. </P> */
static Class<?> defineClass(String name, byte[] bytes, int off, int len,
final ClassLoader parentClassLoader)
{
// 建立一个DelegatingClassLoader用来加载生成的类
ClassLoader newLoader = AccessController.doPrivileged(
new PrivilegedAction<ClassLoader>() {
public ClassLoader run() {
return new DelegatingClassLoader(parentClassLoader);
}
});
return unsafe.defineClass(name, bytes, off, len, newLoader, null);
}
复制代码
经过上面代码及注释，发现生成的类是绑定在DelegatingClassLoader这个加载器上的，也就是说只有经过该加载器才能load生成的类，然而在log4j的ThrowableProxy#loadClass方法并无尝试该类加载器，因此加载不到也是很正常的了。
疑问点三
为何会引发阻塞,和发布的改动点有哪些联系?
分析至此，引发阻塞的缘由就清楚了，是由于jvm对待反射的优化，使得动态生成的类始终不能经过classLoader加载，因而每次解析异常栈都会进行类加载，而且因为双亲委派和ThrowableProxy#loadClass的屡次异常处理，致使锁占有的时间很长，最终致使阻塞。
关于发布改动点，就是加上了@RefreshScope注解，经过对比加了和没加的异常栈日志，也发现了差异。
没有加@RefreshScope注解的异常栈：
com.dianwoda.delibird.common.domain.DeliException:
at com.dianwoda.delibird.push.manager.PushManager.send(PushManager.java:104) ~[classes/:?]
at com.dianwoda.delibird.push.provider.DeliPushProviderImpl.lambda$send$0(DeliPushProviderImpl.java:84) ~[classes/:?]
at com.dianwoda.delibird.common.tool.DeliRunnable.run(DeliRunnable.java:26) ~[classes/:?]
at com.dianwoda.delibird.common.traffic.FastCommander.lambda$runnersEnter$0(FastCommander.java:174) ~[classes/:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_161]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_161]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_161]
复制代码
加了@RefreshScope注解的异常栈：
com.dianwoda.delibird.common.domain.DeliException:
at com.dianwoda.delibird.push.manager.PushManager.send(PushManager.java:104) ~[classes/:?]
at sun.reflect.GeneratedMethodAccessor204.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_161]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_161]
at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:216) ~[spring-core-4.3.15.RELEASE.jar:4.3.15.RELEASE]
at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:472) ~[spring-cloud-context-1.3.3.RELEASE.jar:1.3.3.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.15.RELEASE.jar:4.3.15.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) ~[spring-aop-4.3.15.RELEASE.jar:4.3.15.RELEASE]
at com.dianwoda.delibird.push.manager.PushManager$$EnhancerBySpringCGLIB$$14df0707.send(<generated>) ~[classes/:?]
at com.dianwoda.delibird.push.provider.DeliPushProviderImpl.lambda$send$0(DeliPushProviderImpl.java:84) ~[classes/:?]
at com.dianwoda.delibird.common.tool.DeliRunnable.run(DeliRunnable.java:26) ~[classes/:?]
at com.dianwoda.delibird.common.traffic.FastCommander.lambda$runnersEnter$0(FastCommander.java:174) ~[classes/:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_161]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_161]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_161]
复制代码
@RefreshScope的原理
该注解是spring-cloud中用来在配置更新后刷新bean，其原理以下：
- @RefreshScope 内嵌入了@Scope注解, 用于Spring Scope机制，便是把bean分红不一样类型，控制Bean如何经过BeanFactory返回。
- 经过
RefreshScope的父类方法GenericScope#postProcessBeanFactory把本身注册到beanFactory中，而实现了Scope接口的GenericScope#get的方法，会在get时放入StandardScopeCache缓存中， 其实声明了RefreshScope的bean都是懒加载，在初次使用时才进行建立并缓存。 - 当调用
RefreshScope#refresh方法时，先从缓存中删除先前的Bean，而后再执行GenericScope.BeanLifecycleWrapper#destroy方法完全结束上一个Bean生命周期，而后再发布一个RefreshScopeRefreshedEvent事件。 - 当一个Bean的method被调用的时候，因为这个bean是被代理的，会触发
org.springframework.aop.framework.CglibAopProxy.DynamicAdvisedInterceptor#intercept方法，方法中会调用org.springframework.aop.target.SimpleBeanTargetSource#getTarget从新生成一个bean 放入StandardScopeCache中，从而实现了bean更新
从上面的原理看出通过@RefreshScope注解过的bean就是一个代理，这也不难理解为何会用到反射，而后因为jvm对反射的优化而产生该问题
总结
该问题的缘由，其实有不少方面：
- 从表面看来是加了个
@RefreshScope注解致使的 - 从自身看来是打了太多异常栈
- 从log4j来看是
log4j 2.7的队列满了以后的默认处理策略问题 - 另外对于log4j看来实际上是一个须要优化的地方，对于动态生成的类就应该特殊处理，选择正确的类加载器，或者不进行类加载
参考
相关文章
- 1. 关于高并发问题
- 2. 一个关于AJAX并发的问题
- 3. 关于并发的问题
- 4. 关于java高并发问题总结
- 5. 15个PHP关于高并发的面试题（总结）
- 6. [并发编程]-关于 CAS 的几个问题
- 7. 一次关于fastjson的多线程并发问题的排查
- 8. 关于update操做并发问题
- 9. 关于PhantomReference研究的一个问题
- 10. 一个关于React.Component.setState的问题
- 更多相关文章...
- • Redis悲观锁解决高并发抢红包的问题 - 红包项目实战
- • Redis乐观锁解决高并发抢红包的问题 - 红包项目实战
- • ☆基于Java Instrument的Agent实现
- • NewSQL-TiDB相关
相关标签/搜索
每日一句
-
每一个你不满意的现在，都有一个你没有努力的曾经。
欢迎关注本站公众号,获取更多信息
相关文章