原文連接:blog.fliaping.com/a-high-conc…html
日誌應該是一個應用的基礎組件, 其中老牌的log4j應該是咱們用的最多的, 後來互聯網發展,你們都朝着高併發的方向發力,發現log4j性能不行,由於競爭鎖致使阻塞,性能跟不上. 後來其創始人另立門戶logback後, log4j的新主子Apache進行了大的升級改造,就是現在的log4j2, 其異步日誌的性能也是一騎絕塵, 然而其使用過程當中依然有不少坑,稍不留意就會搞我的仰馬翻. 下面先列舉一些別人踩過的log4j的坑:java
一個APP推送服務,在一次發佈以後, 當遇到批量推送任務時, 線程池打滿, 隊列打滿, 任務堆積. (注: 因爲該次發佈的改動點很普通, 沒有先懷疑該點.)spring
@RefreshScope
註解如下日誌爲改成異步日誌(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對待反射有兩種方式:
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]
複製代碼
該註解是spring-cloud中用來在配置更新後刷新bean,其原理以下:
RefreshScope
的父類方法GenericScope#postProcessBeanFactory
把本身註冊到beanFactory中,而實現了Scope接口的GenericScope#get
的方法,會在get時放入StandardScopeCache
緩存中, 其實聲明瞭RefreshScope
的bean都是懶加載,在初次使用時才進行建立並緩存。RefreshScope#refresh
方法時,先從緩存中刪除先前的Bean,而後再執行GenericScope.BeanLifecycleWrapper#destroy
方法完全結束上一個Bean生命週期,而後再發佈一個RefreshScopeRefreshedEvent
事件。org.springframework.aop.framework.CglibAopProxy.DynamicAdvisedInterceptor#intercept
方法,方法中會調用org.springframework.aop.target.SimpleBeanTargetSource#getTarget
從新生成一個bean 放入 StandardScopeCache
中,從而實現了bean更新從上面的原理看出通過@RefreshScope註解過的bean就是一個代理,這也不難理解爲何會用到反射,而後因爲jvm對反射的優化而產生該問題
該問題的緣由,其實有不少方面:
@RefreshScope
註解致使的log4j 2.7
的隊列滿了以後的默認處理策略問題