老哥,你遇到過log4j2線程阻塞的場景嗎?

2019-11-05     程式設計師聖經

作者:Ye_yang

來源:https://www.cnblogs.com/yeyang/p/10400486.html

在使用log4j2打日誌時,當發生大量異常時,造成大量線程block問題的問題。



# 大量線程block原因



發生異常,列印異常棧時,會調用org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace方法。

ThrowableProxy.toExtendedStackTrace內部會進行loadClass操作。



並且可以看到ClassLoader的loadClass在加載類時



1.首先會持有鎖。

2.調用findLoadedClass看下是否類已經被加載過了

3.如果類沒被加載過,根據雙親委派模型去加載類。



可以看到當某個類被加載過了,調用findLoadedClass會直接返回,鎖也會被很快釋放掉,無需經過雙親委派等後面的一系列步驟。



但是,在進行反射調用時,JVM會進行優化,會動態生成名為sun.reflect.GeneratedMethodAccessor的類,這個類無法通過ClassLoader.loadClass方法加載(為什麼無法通過ClassLoader.loadClass加載?因為JVM內部自定義一個加載器DelegatingClassLoader來加載這個類,這導致應用類加載器 Launcher$AppClassLoader找不到它)。



導致每次解析異常棧進行類加載時,鎖占有的時間很長,最終導致阻塞。



# 關於JVM對反射調用的優化



Java中對反射的優化



使用反射調用某個類的方法,jvm內部有兩種方式



1.JNI:使用native方法進行反射操作。



2.pure-Java:生成bytecode進行反射操作,即生成類sun.reflect.GeneratedMethodAccessor,它是一個被反射調用方法的包裝類,代理不同的方法,類後綴序號會遞增。這種方式第一次調用速度較慢,較之第一種會慢3-4倍,但是多次調用後速度會提升20倍



對於使用JNI的方式,因為每次都要調用native方法再返回,速度會比較慢。所以,當一個方法被反射調用的次數超過一定次數(默認15次)時,JVM內部會進行優化,使用第2種方法,來加快運行速度。



JVM有兩個參數來控制這種優化

-Dsun.reflect.inflationThreshold= value默認為15,即反射調用某個方法15次後,會由JNI的方式變為pure-java的方式



-Dsun.reflect.noInflation=true

默認為false。當設置為true時,表示在第一次反射調用時,就轉為pure-java的方式

下面是一個驗證反射優化的樣例:

配置如下JVM參數,使得在第一次反射調用時,就轉為pure-java的方式





打斷點跟蹤:



可以看到GeneratedMethodAccessor1的classLoader為DelegatingClassLoader,其parent為AppClassLoader。





# 如何關閉JVM對反射調用的優化?



想關閉JVM對反射優化怎麼辦?



JVM中只提供了兩個參數,因此,沒有辦法完全關閉反射優化。



一種能想到的接近於關閉反射優化的方法就是將inflationThreshold設為的一個特別大的數。



inflationThreshold是java中的int型值,可以考慮把其設置為Integer.MAX_VALUE ((2^31)-1)。

$ java-Dsun.reflect.inflationThreshold=2147483647MyApp

文章來源: https://twgreatdaily.com/zh-hk/PlzTPW4BMH2_cNUgNN-p.html