记录一次huawei sdk依赖 log4j导致，项目日志打印不正常的记录；log4j和Slf4j冲突导致tomcat日志不打印

记录一次huawei sdk依赖 log4j导致，项目日志打印不正常的记录；log4j和Slf4j冲突导致tomcat日志不打印

问题描述

• 项目启动是发现日志中不打印tomcat启动日志，并且其实修改了

• 正常的日志

  • 

• 异常的日志

  • 

排查过程

1. 虽然不仅仅是tomcat启动日志没打印，但是可以通过排查tomcat日志来确定问题。所以查找TomcatWebServer类，找到打印"Tomcat started on port(s) …" 的日志行

   • 

2. 找到了 logger.info。但是日志打印，看了下logger的config，发现logLevel是 ERROR

   • 

3. 既然loggerConfigLevel是ERROR，那就找到问题了，ERROR级别，INFO日志不打印。那接下来就要排查为什么logger的ConfigLevel是Error了。接下去就要追溯logger的构造和初始化过程，一般logger都是以静态常量构造初始化的，发现在TomcatWebServer中 logger也是如此，通过LogFactory.getLog(TomcatWebServer.class) 初始化。接下去构造和初始化过程

   • 

4. 接下去整理LogFactory.getLog()的方法栈

   • LogFactory.getLog(Class<?> clazz) -> LogFactory.getLog(String name) -> LogAdapter.createLog(name);
     
     public abstract class LogFactory {
     
     	/**
     	 * Convenience method to return a named logger.
     	 * @param clazz containing Class from which a log name will be derived
     	 */
     	public static Log getLog(Class<?> clazz) {
     		return getLog(clazz.getName());
     	}
     
     	/**
     	 * Convenience method to return a named logger.
     	 * @param name logical name of the <code>Log</code> instance to be returned
     	 */
     	public static Log getLog(String name) {
     		return LogAdapter.createLog(name);
     	}
     }
     
     final class LogAdapter {
     
     	private static final String LOG4J_SPI = "org.apache.logging.log4j.spi.ExtendedLogger";
     
     	private static final String LOG4J_SLF4J_PROVIDER = "org.apache.logging.slf4j.SLF4JProvider";
     
     	private static final String SLF4J_SPI = "org.slf4j.spi.LocationAwareLogger";
     
     	private static final String SLF4J_API = "org.slf4j.Logger";
     
     
     	private static final LogApi logApi;
     
     	static {
     		if (isPresent(LOG4J_SPI)) {
     			if (isPresent(LOG4J_SLF4J_PROVIDER) && isPresent(SLF4J_SPI)) {
     				// log4j-to-slf4j bridge -> we'll rather go with the SLF4J SPI;
     				// however, we still prefer Log4j over the plain SLF4J API since
     				// the latter does not have location awareness support.
     				logApi = LogApi.SLF4J_LAL;
     			}
     			else {
     				// Use Log4j 2.x directly, including location awareness support
     				logApi = LogApi.LOG4J;
     			}
     		}
     		else if (isPresent(SLF4J_SPI)) {
     			// Full SLF4J SPI including location awareness support
     			logApi = LogApi.SLF4J_LAL;
     		}
     		else if (isPresent(SLF4J_API)) {
     			// Minimal SLF4J API without location awareness support
     			logApi = LogApi.SLF4J;
     		}
     		else {
     			// java.util.logging as default
     			logApi = LogApi.JUL;
     		}
     	}
     
     
     	private LogAdapter() {
     	}
     
     
     	/**
     	 * Create an actual {@link Log} instance for the selected API.
     	 * @param name the logger name
     	 */
     	public static Log createLog(String name) {
     		switch (logApi) {
     			case LOG4J:
     				return Log4jAdapter.createLog(name);
     			case SLF4J_LAL:
     				return Slf4jAdapter.createLocationAwareLog(name);
     			case SLF4J:
     				return Slf4jAdapter.createLog(name);
     			default:
     				// Defensively use lazy-initializing adapter class here as well since the
     				// java.logging module is not present by default on JDK 9. We are requiring
     				// its presence if neither Log4j nor SLF4J is available; however, in the
     				// case of Log4j or SLF4J, we are trying to prevent early initialization
     				// of the JavaUtilLog adapter - e.g. by a JVM in debug mode - when eagerly
     				// trying to parse the bytecode for all the cases of this switch clause.
     				return JavaUtilAdapter.createLog(name);
     		}
     	}
     }
     

   • 最后发现在LogAdapter中的logApi值为LOG4J，所以最终会通过Log4jAdapter.createLog(name)来创建Log logger对象

     • 

     • 	private static class Log4jAdapter {
       
       		public static Log createLog(String name) {
       			return new Log4jLog(name);
       		}
       	}
       	
       	
       

     • 	private static class Log4jLog implements Log, Serializable {
       
       		private static final String FQCN = Log4jLog.class.getName();
       
       		private static final LoggerContext loggerContext =
       				LogManager.getContext(Log4jLog.class.getClassLoader(), false);
       
       		private final ExtendedLogger logger;
       
       		public Log4jLog(String name) {
       			LoggerContext context = loggerContext;
       			if (context == null) {
       				// Circular call in early-init scenario -> static field not initialized yet
       				context = LogManager.getContext(Log4jLog.class.getClassLoader(), false);
       			}
       			this.logger = context.getLogger(name);
       		}
       	}
       

     • public class LoggerContext extends AbstractLifeCycle
               implements org.apache.logging.log4j.spi.LoggerContext, AutoCloseable, Terminable, ConfigurationListener,
               LoggerContextShutdownEnabled {
           
           @Override
           public Logger getLogger(final String name) {
               return getLogger(name, null);
           }
                   
                   
           @Override
           public Logger getLogger(final String name, final MessageFactory messageFactory) {
               // Note: This is the only method where we add entries to the 'loggerRegistry' ivar.
               Logger logger = loggerRegistry.getLogger(name, messageFactory);
               if (logger != null) {
                   AbstractLogger.checkMessageFactory(logger, messageFactory);
                   return logger;
               }
       
               logger = newInstance(this, name, messageFactory);
               loggerRegistry.putIfAbsent(name, messageFactory, logger);
               return loggerRegistry.getLogger(name, messageFactory);
           }
       }
       

     •     protected Logger(final LoggerContext context, final String name, final MessageFactory messageFactory) {
               super(name, messageFactory);
               this.context = context;
               privateConfig = new PrivateConfig(context.getConfiguration(), this);
           }
       

     •         public PrivateConfig(final Configuration config, final Logger logger) {
                   this.config = config;
                   this.loggerConfig = config.getLoggerConfig(getName());
                   this.loggerConfigLevel = this.loggerConfig.getLevel();
                   this.intLevel = this.loggerConfigLevel.intLevel();
                   this.logger = logger;
                   this.requiresLocation = this.loggerConfig.requiresLocation();
               }
       

   • 接下去一级级寻找LogConfigLevel的赋值，最终在org.apache.logging.log4j.core.Logger的构造方法中，调用了PrivateConfig构造方法，在org.apache.logging.log4j.core.PrivateConfig构造方法中对loggerConfigLevel进行了初始化赋值

     • 

5. 对比正常打印日志的项目发现，正常的项目使用的是org.slf4j.Log

   • 

   • 继续下钻可以看到org.slf4j.Log的默认打印级别是DEBUG

     • 

6. 到这里可以确定问题是，由于在LogAdapter中选择的Logger 不同导致的日志不同，而其中LogAdapter的logApi值起到决定性作用，这里又出现了新的方向，需要查看logApi的值是怎么初始化的

   • 

7. 整理logApi的逻辑是怎么初始化，logApi是在LogAdapter类中的静态块中的，由于存在org.apache.logging.log4j.spi.ExtendedLogger，但是不存在org.apache.logging.slf4j.SLF4JProvider，导致最终logApi = LogApi.LOG4J

   • 

   • 

8. 最终排查到问题由于org.apache.logging.log4j.spi.ExtendedLogger 的存在，导致最终logger选择了log4j。而org.apache.logging.log4j.spi.ExtendedLogger存在于log4j-api-2.13.3.jar 中

   • 

9. log4j-api-2.13.3.jar是在maven中的com.huaweicloud依赖加载进项目的

   • 

10. 最终解决剔除log4j-api依赖，解决问题

    •     <dependency>
            <groupId>com.huaweicloud</groupId>
            <artifactId>esdk-obs-java-bundle</artifactId>
            <version>${huawei.oss.version}</version>
            <exclusions>
              <exclusion>
                <groupId>org.apache.logging.log4j</groupId>
                <artifactId>log4j-api</artifactId>
              </exclusion>
            </exclusions>
          </dependency>
      

解决方法

• 剔除log4j-api依赖，解决问题

  •     <dependency>
          <groupId>com.huaweicloud</groupId>
          <artifactId>esdk-obs-java-bundle</artifactId>
          <version>${huawei.oss.version}</version>
          <exclusions>
            <exclusion>
              <groupId>org.apache.logging.log4j</groupId>
              <artifactId>log4j-api</artifactId>
            </exclusion>
          </exclusions>
        </dependency>