JVM反调调用优化，导致发生大量异常时log4j2线程阻塞

Posted 2021-04-17 占小狼的博客

tags:

篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了JVM反调调用优化，导致发生大量异常时log4j2线程阻塞相关的知识，希望对你有一定的参考价值。

优质文章，及时送达

来源：https://url.cn/5GtrQyo

在使用log4j2打日志时，当发生大量异常时，造成大量线程block问题的问题。

大量线程block原因

发生异常，打印异常栈时，会调用org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace方法。 JVM反调调用优化，导致发生大量异常时log4j2线程阻塞

JVM反调调用优化，导致发生大量异常时log4j2线程阻塞

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内部有两种方式

JNI：使用native方法进行反射操作。
pure-Java：生成bytecode进行反射操作，即生成类sun.reflect.GeneratedMethodAccessor ，它是一个被反射调用方法的包装类，代理不同的方法，类后缀序号会递增。这种方式第一次调用速度较慢，较之第一种会慢3-4倍，但是多次调用后速度会提升20倍

对于使用JNI的方式，因为每次都要调用native方法再返回，速度会比较慢。所以，当一个方法被反射调用的次数超过一定次数（默认15次）时，JVM内部会进行优化，使用第2种方法，来加快运行速度。

JVM有两个参数来控制这种优化

-Dsun.reflect.inflationThreshold=<value>value默认为15，即反射调用某个方法15次后，会由JNI的方式变为pure-java的方式

-Dsun.reflect.noInflation=true

默认为false。当设置为true时，表示在第一次反射调用时，就转为pure-java的方式

下面是一个验证反射优化的样例：

 
   
   
 
  
    
    
  public class TestMethodInvoke {
  
    
    
   public static void main(String[] args) throws Exception {
  
    
    
   Class<?> clz = Class.forName("A");
  
    
    
   Object o = clz.newInstance();
  
    
    
   Method m = clz.getMethod("foo", String.class);
  
    
    
   for (int i = 0; i < 100; i++) {
  
    
    
   m.invoke(o, Integer.toString(i));
  
    
    
   }
  
    
    
   }
  
    
    
  }

 
   
   
 
  
    
    
  public class A {
  
    
    
   public void foo(String name) {
  
    
    
   System.out.println("Hello, " + name);
  
    
    
   }
  
    
    
  }