前言
? ? ? 隨著業(yè)務(wù)的快速增長慌洪，日志導(dǎo)致的線程 Block 問題愈發(fā)頻繁只冻。比如調(diào)用后端 RPC 服務(wù)超時株憾，導(dǎo)致調(diào)用方大量線程 Block蝙寨；再比如，業(yè)務(wù)內(nèi)部輸出異常日志導(dǎo)致服務(wù)大量線程 Block 等号胚，這些問題嚴(yán)重影響著服務(wù)的穩(wěn)定性籽慢。
AsyncAppender 導(dǎo)致線程 Block
? ? ? ? 通過監(jiān)控平臺查看線程監(jiān)控指標(biāo)浸遗，從 Blocked 線程堆棧不難看出是跟日志打印相關(guān)猫胁，由于是 ERROR 級別日志，查看具體報錯日志跛锌，發(fā)現(xiàn)有兩種業(yè)務(wù)異常弃秆。
? ? ? ? 從 Blocked 線程堆棧中可以看出，線程阻塞在類加載流程上髓帽，發(fā)現(xiàn)加載類時確實會根據(jù)類名來加 synchronized 同步塊菠赚，因此初步猜測是類加載導(dǎo)致線程 Block。
注意：
1郑藏、項目代碼里只是普通地輸出一條 ERROR 日志而已衡查，為何會觸發(fā)類加載？
2必盖、通常情況下類加載幾乎不會觸發(fā)線程 Block拌牲，不然一個項目要加載成千上萬個類，如果因為加載類就導(dǎo)致 Block歌粥，那項目就沒法正常運行了塌忽。
為什么會觸發(fā)類加載？
? ? ? 從 Blocked 線程堆棧著手分析失驶，查看堆棧中的 ThrowableProxy 相關(guān)代碼土居，發(fā)現(xiàn)其構(gòu)造函數(shù)會遍歷整個異常堆棧中的所有堆棧元素，最終獲取所有堆棧元素類所在的 JAR 名稱和版本信息。
具體流程如下：
1擦耀、首先獲取堆棧元素的類名稱棉圈。
2、再通過 loadClass 的方式獲取對應(yīng)的 Class 對象眷蜓。
3迄损、進(jìn)一步獲取該類所在的 JAR 信息，從 CodeSource 中獲取 JAR 名稱账磺，從Package 中獲取 JAR 版本芹敌。
? ? ? ? 當(dāng)前問題已在2.11.1版本中修復(fù)，通過讓 get/put 方法使用同一個 key 來修復(fù)緩存的有效性問題垮抗，但由于 ThrowableProxy 對每個 Throwable 都會創(chuàng)建一個全新的 Map氏捞，而不是使用全局 Map，因此其緩存也僅僅對單個 Throwable 生效冒版。
? ? ? ? 上述問題從源碼中可以看到液茎，ThrowableProxy#toExtendedStackTrace 方法通過 Map緩存當(dāng)前堆棧元素類對應(yīng)的 CacheEntry，來避免重復(fù)解析 CacheEntry辞嗡，但是由于Map 緩存 put 操作使用的 key 來自于 StackTraceElement.toString 方法捆等，而 get操作使用的 key 卻來自于 StackTraceElement.getClassName 方法，即使對于同一個 StackTraceElement 而言续室，其 toString 和 getClassName 方法對應(yīng)的返回結(jié)果也不一樣栋烤，所以此 map 形同虛設(shè)。
? ? ? 通常情況下一個類加載器對于一個類只會加載一次挺狰，類加載器內(nèi)部保存有類緩存明郭，無需重復(fù)加載，但目前的現(xiàn)象卻是由于類加載而導(dǎo)致線程大量 Block丰泊，因此必然是有些類加載不了薯定，且不斷重復(fù)嘗試加載，那到底是什么類無法加載呢
到底什么類加載不了瞳购？(分析業(yè)務(wù)異常的具體堆棧)
兩份堆椈爸叮基本相似，且大多數(shù)類都是很普通的類学赛，但是唯一不同的地方在于：
1年堆、sun.reflect.NativeMethodAccessorImpl
2、sun.reflect.GeneratedMethodAccessor261
? ? ? 從字面信息中不難猜測出這與反射調(diào)用相關(guān)罢屈，但問題是這兩份堆棧對應(yīng)的其實是同一份業(yè)務(wù)代碼嘀韧，查閱相關(guān)資料得知，這與 JVM 反射調(diào)用相關(guān).
JVM 對反射調(diào)用分兩種情況：
1缠捌、默認(rèn)使用 native 方法進(jìn)行反射操作锄贷。
2译蒂、一定條件下會生成字節(jié)碼進(jìn)行反射操作，即生成 sun.reflect.GeneratedMethodAccessor<N> 類谊却，它是一個反射調(diào)用方法的包裝類柔昼，代理不同的方法，類后綴序號遞增炎辨。
? ? ? 從源碼的 MethodAccessorGenerator#generateName 方法可以看到捕透，字節(jié)碼生成的類名稱規(guī)則是 sun.reflect.GeneratedConstructorAccessor<N>，其中 N 是從 0 開始的遞增數(shù)字碴萧，且生成類是由 DelegatingClassLoader 類加載器定義乙嘀，所以其他類加載器無法加載該類，也就無法生成類緩存數(shù)據(jù)破喻，從而導(dǎo)致每次加載類時都需要遍歷JarFile虎谢，極大地降低了類查找速度，且類加載過程是 synchronized 同步調(diào)用曹质，在高并發(fā)情況下會更加惡化婴噩，從而導(dǎo)致線程 Block。
JVM 反射調(diào)用為什么要做這么做羽德？
? ? ? 這是 JVM 對反射調(diào)用的一種優(yōu)化手段几莽，在 sun.reflect.ReflectionFactory 的文檔注釋里對此做了解釋，這是一種“Inflation”機(jī)制宅静，加載字節(jié)碼的調(diào)用方式在第一次調(diào)用時會比 Native 調(diào)用的速度要慢 3~4 倍章蚣，但是在后續(xù)調(diào)用時會比 Native 調(diào)用速度快 20 多倍。為了避免反射調(diào)用影響應(yīng)用的啟動速度坏为，所以在反射調(diào)用的前幾次通過 Native 方式調(diào)用究驴，當(dāng)超過一定調(diào)用次數(shù)后使用字節(jié)碼方式調(diào)用，提升反射調(diào)用性能匀伏。
普通通地打印一條 ERROR 日志，為何會導(dǎo)致解析蝴韭、加載異常堆棧類够颠？
? ? ? ? ? AsyncAppender 在生成 LogEvent 的快照 Log4jLogEvent 時，會先對 LogEvent序列化處理統(tǒng)一轉(zhuǎn)換為 LogEventProxy榄鉴。
此時不同類型的 LogEvent 的處理情況稍有差異：
● Log4jLogEvent 類 型履磨， 先 執(zhí) 行 Log4jLogEvent#getThrownProxy 方 法，觸發(fā)創(chuàng)建 ThrowableProxy 實例庆尘。
● MutableLogEvent 類型剃诅，先創(chuàng)建 LogEventProxy 實例，在構(gòu)造函數(shù)內(nèi)執(zhí)行 MutableLogEvent#getThrownProxy 方法驶忌，觸發(fā)創(chuàng)建 ThrowableProxy實例矛辕。
? ? ? ? 不管 LogEvent 的實際類型是 MutableLogEvent 還是 Log4jLogEvent笑跛，最終都會觸發(fā)創(chuàng)建 ThrowableProxy 實例，并在 ThrowableProxy 構(gòu)造函數(shù)內(nèi)觸發(fā)了解析聊品、加載異常堆棧類飞蹂。
問題小結(jié)
? ? ? ? Log4j2 打印異常日志時，AsyncAppender 會先創(chuàng)建日志事件快照翻屈，并進(jìn)一步觸發(fā)解析陈哑、加載異常堆棧類。JVM 通過生成字節(jié)碼的方式優(yōu)化反射調(diào)用性能伸眶，但該動態(tài)生成的類無法被 WebAppClassLoader 類加載器加載惊窖，因此當(dāng)大量包含反射調(diào)用的異常堆棧被輸出到日志時，會頻繁地觸發(fā)類加載厘贼，由于類加載過程是 synchronized同步加鎖的爬坑，且每次加載都需要讀取文件，速度較慢涂臣，從而導(dǎo)致線程 Block盾计。
