Using Custom ClassLoader to Isolate Log42j and Slf4j. Console log: Properties contains an invalid element or attribute "property"

[zhanjinhao]

env:

1. log4j2 version: 2.17.2
2. slf4j version: 1.7.36
3. jdk version: 8
4. os version: win11

Requirements

I want to develop an Agent to trace service status. To isolate Log42j and Slf4j, I develop a custom classloader which named LogClassLoader.

The main requirements are:

1. Load jar from specific directory, not the AppClassLoader's classpath
2. Load log4j2.xml from specific direcotry
3. output the msg to the path defined in log4j2.xml.

Code and Problem

LogClassLoader override loadClass() method. When it works, if the name has prefix about Log4j2 or Slf4j, I will load class from the specific directory. the code about LogClassLoader is copy from apache skywalking AgentClassLoader. The code of LogClassLoader is:

/**
 * 用于加载插件和插件的拦截器
 */
public class LogClassLoader extends ClassLoader {

  /**
   * 用于加载日志组件的加载器
   */
  @Getter
  private static LogClassLoader DEFAULT_LOADER;

  /**
   * 自定义类加载器加载类的路径
   */
  private File classpath;
  private List<Jar> allJarList;
  private ReentrantLock jarScanLock = new ReentrantLock();

  public LogClassLoader(ClassLoader parent) {
    super(parent);

    File agentJarDir = AgentPackagePath.getPath();
    System.out.println(String.format("logLibDir: %s", agentJarDir));

    classpath = new File(new File(agentJarDir, "lib"), "log");
    getAllJarList();
  }

  public static void initDefaultLoader() {
    if (DEFAULT_LOADER == null) {
      DEFAULT_LOADER = new LogClassLoader(LogClassLoader.class.getClassLoader());
    }
  }

  private static List<String> logPrefixList = new ArrayList<>();

  static {
    logPrefixList.add("org.slf4j.");
    logPrefixList.add("org.apache.logging.log4j.");
    logPrefixList.add("org.apache.logging.slf4j.");
  }

  @Override
  public Class<?> loadClass(String name, boolean resolve) throws ClassNotFoundException {
    for (String logPrefix : logPrefixList) {
      if (name.startsWith(logPrefix)) {
        Class<?> aClass = doFindClass(name);
        if (resolve) {
          resolveClass(aClass);
        }
      }
    }

    return super.loadClass(name, resolve);
  }

  /**
   * loadClass --> findClass（自定义自己的类加载逻辑） --> defineClass
   */
  @Override
  protected Class<?> findClass(String name) throws ClassNotFoundException {
    return super.findClass(name);
  }

  private Class<?> doFindClass(String name) throws ClassNotFoundException {
    List<Jar> _allJarList = getAllJarList();

    String concat = name.replace(".", "/").concat(".class");
    for (Jar jar : _allJarList) {
      JarEntry jarEntry = jar.jarFile.getJarEntry(concat);
      if (jarEntry == null) {
        continue;
      }
      try {
        URL url = new URL("jar:file:" + jar.sourceFile.getAbsolutePath() + "!/" + concat);
        byte[] byteArray = IOUtils.toByteArray(url);
        return defineClass(name, byteArray, 0, byteArray.length);
      } catch (Exception e) {
        System.out.println(String.format("find class %s error", name));
      }
    }
    throw new ClassNotFoundException("can not find " + name);
  }

  private List<Jar> getAllJarList() {
    if (allJarList == null) {
      jarScanLock.lock();
      try {
        if (allJarList == null) {
          allJarList = doGetJars();
        }
      } finally {
        jarScanLock.unlock();
      }
    }
    return allJarList;
  }

  private List<Jar> doGetJars() {
    List<Jar> _allJarList = new ArrayList<>();

    if (classpath.exists() && classpath.isDirectory()) {
      String[] list = classpath.list(new FilenameFilter() {
        @Override
        public boolean accept(File dir, String name) {
          return name.endsWith(".jar");
        }
      });
      if (list == null || list.length == 0) {
        return _allJarList;
      }
      for (String s : list) {
        File jarSourceFile = new File(classpath, s);
        try {
          Jar jar = new Jar(new JarFile(jarSourceFile), jarSourceFile);
          _allJarList.add(jar);
          System.out.println(String.format("load jar %s success.", jarSourceFile));
        } catch (Exception e) {
          System.out.println(String.format("jar %s load fail.", jarSourceFile));
          e.printStackTrace();
        }
      }
    }

    return _allJarList;
  }

  private static class Jar {
    /**
     * jar文件对对应的jarFile对象
     */
    private final JarFile jarFile;
    /**
     * jar文件
     */
    private final File sourceFile;

    public Jar(JarFile jarFile, File sourceFile) {
      this.jarFile = jarFile;
      this.sourceFile = sourceFile;
    }
  }

}

My log4j2.xml is :

<?xml version="1.0" encoding="UTF-8"?>
<configuration monitorInterval="5">
  <!--变量配置-->
  <Properties>
    <!-- 格式化输出：%date表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度 %msg：日志消息，%n是换行符-->
    <!-- %logger{36} 表示 Logger 名字最长36个字符 -->
    <property name="LOG_PATTERN">external3333 - %date{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</property>
    <!-- 定义日志存储的路径 -->
    <property name="FILE_PATH">./agent_logs</property>
    <property name="FILE_NAME">agentLogs</property>
  </Properties>
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <!--设置日志格式及颜色-->
      <PatternLayout
              pattern="external3333 - %date{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"
              disableAnsi="false" noConsoleNoAnsi="false"/>
    </Console>
    <!--文件会打印出所有信息，这个log每次运行程序会自动清空，由append属性决定，适合临时测试用-->
    <File name="Filelog" fileName="${FILE_PATH}/test.log" append="false">
      <PatternLayout pattern="${LOG_PATTERN}"/>
    </File>
    <!-- 这个会打印出所有的info及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileInfo" fileName="${FILE_PATH}/info.log"
                 filePattern="${FILE_PATH}/${FILE_NAME}-INFO-%d{yyyy-MM-dd}_%i.log.gz">
      <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
      <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
      <PatternLayout pattern="${LOG_PATTERN}"/>
      <Policies>
        <!--interval属性用来指定多久滚动一次，默认是1 hour-->
        <TimeBasedTriggeringPolicy interval="1"/>
        <SizeBasedTriggeringPolicy size="10MB"/>
      </Policies>
      <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
      <DefaultRolloverStrategy max="15"/>
    </RollingFile>
    <!-- 这个会打印出所有的warn及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileWarn" fileName="${FILE_PATH}/warn.log"
                 filePattern="${FILE_PATH}/${FILE_NAME}-WARN-%d{yyyy-MM-dd}_%i.log.gz">
      <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
      <ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/>
      <PatternLayout pattern="${LOG_PATTERN}"/>
      <Policies>
        <!--interval属性用来指定多久滚动一次，默认是1 hour-->
        <TimeBasedTriggeringPolicy interval="1"/>
        <SizeBasedTriggeringPolicy size="10MB"/>
      </Policies>
      <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
      <DefaultRolloverStrategy max="15"/>
    </RollingFile>
    <!-- 这个会打印出所有的error及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileError" fileName="${FILE_PATH}/error.log"
                 filePattern="${FILE_PATH}/${FILE_NAME}-ERROR-%d{yyyy-MM-dd}_%i.log.gz">
      <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
      <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
      <PatternLayout pattern="${LOG_PATTERN}"/>
      <Policies>
        <!--interval属性用来指定多久滚动一次，默认是1 hour-->
        <TimeBasedTriggeringPolicy interval="1"/>
        <SizeBasedTriggeringPolicy size="10MB"/>
      </Policies>
      <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
      <DefaultRolloverStrategy max="15"/>
    </RollingFile>
  </Appenders>
  <!--Logger节点用来单独指定日志的形式，比如要为指定包下的class指定不同的日志级别等。-->
  <!--然后定义loggers，只有定义了logger并引入的appender，appender才会生效-->
  <loggers>
    <root level="info">
      <appender-ref ref="Console"/>
      <appender-ref ref="Filelog"/>
      <appender-ref ref="RollingFileInfo"/>
      <appender-ref ref="RollingFileWarn"/>
      <appender-ref ref="RollingFileError"/>
    </root>
  </loggers>
</configuration>

In order to load jar and log4j2.xml from specific directory, I use Class.forName(className, true, LogClassLoader) to load class. And I use reflection api to invoke getContext(ClassLoader.class, boolean.class, URI.class) method to load log4j2.xml, which avoid use the configuration in AppClassLoader's classpath. And the code is:

public class MyLoggerFactory {

  static Class<?> loggerFactoryClass;
  // 添加Logger接口的引用
  private static Class<?> loggerInterface;

  static Method getLoggerString;
  static Method getLoggerClass;

  static Class<?> logManagerClass;
  static Class<?> loggerContextClass;

  static {
    try {
      LogClassLoader.initDefaultLoader();
      LogClassLoader defaultLoader = LogClassLoader.getDEFAULT_LOADER();

      ClassLoader contextClassLoader = Thread.currentThread().getContextClassLoader();
      Thread.currentThread().setContextClassLoader(defaultLoader);

      try {
        loggerFactoryClass = Class.forName("org.slf4j.LoggerFactory", true, defaultLoader);
        loggerInterface = Class.forName("org.slf4j.Logger", true, defaultLoader);
        logManagerClass = Class.forName("org.apache.logging.log4j.LogManager", true, defaultLoader);
        loggerContextClass = Class.forName("org.apache.logging.log4j.core.LoggerContext", true, defaultLoader);

        getLoggerString = loggerFactoryClass.getDeclaredMethod("getLogger", String.class);
        getLoggerClass = loggerFactoryClass.getDeclaredMethod("getLogger", Class.class);

        File agentJarDir = AgentPackagePath.getPath();

        File conFile = new File(new File(new File(AgentPackagePath.getPath(), "lib"), "log"), "log4j2.xml");

//        ConfigurationSource source = new ConfigurationSource(new FileInputStream(conFile), conFile);
//        Configuration configuration = new XmlConfiguration(null, source);
//        Configurator.initialize(configuration);

        // config dist/lib/log/log4j2.xml
        Method getContextMethod = logManagerClass.getDeclaredMethod("getContext", ClassLoader.class, boolean.class, URI.class);
        Object logContext = getContextMethod.invoke(null, null, false, conFile.toURI());
      } finally {
        Thread.currentThread().setContextClassLoader(contextClassLoader);
      }

    } catch (Exception e) {
      e.printStackTrace();
    }
  }

  public static Logger getLogger(Class<?> clazz) {
    try {
      Object invoke = getLoggerClass.invoke(null, clazz);

      // 使用代理模式包装返回的对象，避免类型转换问题
      if (invoke != null) {
        return createLoggerProxy(invoke);
      }
      throw new RuntimeException(String.format("Failed to create logger %s instance", clazz));
    } catch (Exception e) {
      throw new RuntimeException(e);
    }
  }

  // 创建代理Logger实例来避免类加载器问题
  private static Logger createLoggerProxy(Object loggerInstance) {
    // 实现代理逻辑，将方法调用转发给实际的logger实例
    // 这样可以绕过类加载器类型检查问题
    return (Logger) Proxy.newProxyInstance(
            MyLoggerFactory.class.getClassLoader(),
            new Class[]{Logger.class},
            new InvocationHandler() {
              @Override
              public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
                // 在目标对象上查找匹配的方法
                Method targetMethod = loggerInstance.getClass().getMethod(
                        method.getName(), method.getParameterTypes());
                return targetMethod.invoke(loggerInstance, args);
              }
            }
    );
  }

}

When it works, I find it can load jar and log4j2.xml from the specific directory.
BUT, it can not output the msg to the path defined in property of configuration!

The result is it cannot replace the variables of Appenders , although the variables are defined in properties element.

The config can work as expected in springboot's project.

The full demo project is: https://github.com/[zhanjinhao/log-learn](https://github.com/zhanjinhao/log-learn) and it can reproduce the problem. Run Application in springboot way, the console will output "Properties contains an invalid element or attribute "property"" and the file will be created in ${FILE_PATH} not in "agent_logs"

DEBUG

I try to debug the code to find some reason.

in org.apache.logging.log4j.core.config.AbstractConfiguration#doConfigure, the children of Properties is empty.

In springboot project, the children is an List which contains three children.

But i don't know why the children are different. I don't have knowledge about xml parsing.

Can somebody give me some advice! Thank a lot.

[jhl221123]

Hi @zhanjinhao,

I took a look at your ClassLoader and it seems that since it doesn't implement findResource, resources can only be found in the parent classloader. I believe you can create a much simpler implementation by leveraging URLClassLoader.

I've made some changes to demonstrate this, which also include a check for already-loaded classes and support for parallel-capability. You can review the code here :) I've confirmed that with this approach, app_logs and agent_logs are separated correctly.

[zhanjinhao]

Thanks! Thanks!

It meets my needs. I'd also like to get some more details about which file is causing the problem. Are there any debug breakpoint I can analyze, or some articles about log4j2 startup or XML parsing?

[vy]

@zhanjinhao, How do I troubleshoot my setup? FAQ section can be a good starting point.

[zhanjinhao]

@vy thanks.

@jhl221123 I think I've found the real reason. Not about findResource()/findResources(). It is about findLoadedClass().

Problem Analysis

I have compared my implementation with yours. And adjusting my implementation to yours step by step . I found if I don't introduce findLoadedClass() when overriding loadClass(), the directory will not be created correctly.

If I don't extend URLClassLoader. And I still load class and resources in my way except including a check for already-loaded classes. the directory will be created correctly.

/**
 * It will use commons-io package, so I package my project to a fat jar.
 **/
package cn.addenda.loglearn;

import lombok.Getter;
import org.apache.commons.io.IOUtils;

import java.io.File;
import java.io.IOException;
import java.net.URL;
import java.util.ArrayList;
import java.util.Enumeration;
import java.util.Iterator;
import java.util.List;
import java.util.jar.JarEntry;
import java.util.jar.JarFile;

public class LogClassLoader6 extends ClassLoader {

  @Getter
  private static LogClassLoader6 DEFAULT_LOADER;
  private final List<String> logPrefixList = new ArrayList<>();

  List<Jar> jars;

  static {
    ClassLoader.registerAsParallelCapable();
  }

  public LogClassLoader6(ClassLoader parent) {
    super(parent);

    jars = doGetJars();
    logPrefixList.add("org.slf4j.");
    logPrefixList.add("org.apache.logging.log4j.");
    logPrefixList.add("org.apache.logging.slf4j.");
  }

  @Override
  protected Class<?> loadClass(String name, boolean resolve) throws ClassNotFoundException {
    synchronized (getClassLoadingLock(name)) {
      Class<?> loadedClass = findLoadedClass(name);
      if (loadedClass != null) {
        return loadedClass;
      }

      boolean shouldIsolate = false;
      for (String prefix : logPrefixList) {
        if (name.startsWith(prefix)) {
          shouldIsolate = true;
          break;
        }
      }

      if (shouldIsolate) {
        loadedClass = doFindClass(name);
        if (resolve) {
          resolveClass(loadedClass);
        }
        return loadedClass;
      }

      return super.loadClass(name, resolve);
    }
  }


  @Override
  public Enumeration<URL> getResources(String name) throws IOException {
    List<URL> allResources = new ArrayList<>();
    for (Jar jar : jars) {
      JarEntry jarEntry = jar.jarFile.getJarEntry(name);
      if (jarEntry == null) {
        continue;
      }
      try {
        URL url = new URL("jar:file:" + jar.sourceFile.getAbsolutePath() + "!/" + name);
        allResources.add(url);
      } catch (Exception e) {
        System.out.println(String.format("find file {} error", name));
        e.printStackTrace();
      }
    }
    Iterator<URL> iterator = allResources.iterator();
    return new Enumeration<URL>() {
      @Override
      public boolean hasMoreElements() {
        return iterator.hasNext();
      }

      @Override
      public URL nextElement() {
        return iterator.next();
      }
    };
  }

  @Override
  public URL getResource(String name) {
    // todo 设置为线程上下文类加载器，再从这里读取外部目录的log4j2.xml
    for (Jar jar : jars) {
      JarEntry jarEntry = jar.jarFile.getJarEntry(name);
      if (jarEntry == null) {
        continue;
      }
      try {
        // 返回第一个
        URL url = new URL("jar:file:" + jar.sourceFile.getAbsolutePath() + "!/" + name);
        return url;
      } catch (Exception e) {
        System.out.println(String.format("find file {} error", name));
        e.printStackTrace();
      }
    }
    return null;
  }

  public static synchronized void initDefaultLoader() {
    if (DEFAULT_LOADER == null) {
//      ClassLoader extensionClassLoader = ClassLoader.getSystemClassLoader().getParent();
      ClassLoader extensionClassLoader = ClassLoader.getSystemClassLoader();
      DEFAULT_LOADER = new LogClassLoader6(extensionClassLoader);
    }
  }

  private Class<?> doFindClass(String name) throws ClassNotFoundException {
    List<Jar> _allJarList = jars;

    String concat = name.replace(".", "/").concat(".class");
    for (Jar jar : _allJarList) {
      JarEntry jarEntry = jar.jarFile.getJarEntry(concat);
      if (jarEntry == null) {
        continue;
      }
      try {
        URL url = new URL("jar:file:" + jar.sourceFile.getAbsolutePath() + "!/" + concat);
        byte[] byteArray = IOUtils.toByteArray(url);
        return defineClass(name, byteArray, 0, byteArray.length);
      } catch (Exception e) {
        System.out.println(String.format("find class %s error", name));
      }
    }
    throw new ClassNotFoundException("can not find " + name);
  }


  private List<Jar> doGetJars() {
    List<Jar> _allJarList = new ArrayList<>();
    File agentJarDir = AgentPackagePath.getPath();
    System.out.println("Agent base directory: " + agentJarDir);
    File logLibDir = new File(new File(agentJarDir, "lib"), "log");

    if (logLibDir.exists() && logLibDir.isDirectory()) {
      String[] list = logLibDir.list((dir, name) -> name.endsWith(".jar"));
      if (list == null || list.length == 0) {
        return _allJarList;
      }
      for (String s : list) {
        File jarSourceFile = new File(logLibDir, s);
        try {
          Jar jar = new Jar(new JarFile(jarSourceFile), jarSourceFile);
          _allJarList.add(jar);
          System.out.println(String.format("load jar %s success.", jarSourceFile));
        } catch (Exception e) {
          System.out.println(String.format("jar %s load fail.", jarSourceFile));
          e.printStackTrace();
        }
      }
    }
    return _allJarList;
  }

  private static class Jar {
    /**
     * jar文件对对应的jarFile对象
     */
    private final JarFile jarFile;
    /**
     * jar文件
     */
    private final File sourceFile;

    public Jar(JarFile jarFile, File sourceFile) {
      this.jarFile = jarFile;
      this.sourceFile = sourceFile;
    }
  }

}

In my production project, I will extent URLClassLoader because I am indeed not clear about operating jar.

Different Class

With my previous LogClassLoader, the codebelow will output : loggerContextClass != loggerContextClass2.

        loggerFactoryClass = Class.forName("org.slf4j.LoggerFactory", true, defaultLoader);
        loggerFactoryClass2 = Class.forName("org.slf4j.LoggerFactory", true, defaultLoader);
        if (loggerContextClass == loggerFactoryClass2) {
          System.out.println("loggerContextClass == loggerContextClass2");
        } else {
          System.out.println("loggerContextClass != loggerContextClass2");
        }

A class‘s binary is loaded from the jar multiple times, each time the class is different.

Conclusion

So I think the real reason is that I don't check the already-loaded classes

However, as for how it affects log4j2, it's too difficult for me to analyze. Log4j2 loaded too many classes at startup.