欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识！
您现在的位置是： 首页

记一次Log4j.xml配置不当，业务日志不打印到控制台的问题!!!

程序员文章站 2022-05-24 15:28:31
...

问题背景

项目打印日志使用的是log4j，并且是项目启动的时候加载log4j.xml配置文件初始化log4j，为了排查问题方便，修改log4j.xml，增加日志输出到控制台，但之前不小心改过一次，时间久了再使用就不不打印日志到控制台了，也没找到原因，今天看了下log4j的源码，才发现问题!

#log4j.xml配置
如下是我使用的log4j.xml的具体配置（关键部分），相信对log4j.xml比较熟悉的很容易就看出问题所在，但当时还真没看出来

<?xml version="1.0" encoding="gb2312"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

	<appender name="console" class="org.apache.log4j.ConsoleAppender">
		<param name="Target" value="System.out" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d %-5p: %c.%M:%L - %m%n" />
		</layout>
	</appender>
	<appender name="SQL_DEBUG"
		class="com.xxx.sims.uspc.platform.log.TimeSizeRollingFileAppender">
		<param name="File" value="uspc/sql/debug.log" />
		<param name="MaxBackupIndex" value="300" />
		<param name="Encoding" value="GB2312" />
		<param name="MaxFileSize" value="50MB" />
		<param name="DatePattern" value="'.'yyyy-MM-dd" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern"
				value="%d{ISO8601} %p [%c] - [%m]%n" />
		</layout>
		<filter class="org.apache.log4j.varia.LevelRangeFilter">
			<param name="LevelMin" value="debug" />
			<param name="LevelMax" value="debug" />
			<param name="acceptOnMatch" value="true" />
		</filter>
	</appender>

	<!--sql info log file-->
	<appender name="SQL_INFO"
		class="com.xxx.sims.uspc.platform.log.TimeSizeRollingFileAppender">
		<param name="File" value="uspc/sql/info.log" />
		<param name="MaxBackupIndex" value="300" />
		<param name="Encoding" value="GB2312" />
		<param name="MaxFileSize" value="50MB" />
		<param name="DatePattern" value="'.'yyyy-MM-dd" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern"
				value="%d{ISO8601} %p [%c] - [%m]%n" />
		</layout>
		<filter class="org.apache.log4j.varia.LevelRangeFilter">
			<param name="LevelMin" value="info" />
			<param name="LevelMax" value="info" />
			<param name="acceptOnMatch" value="true" />
		</filter>
	</appender>

	<!--sql error log file-->
	<appender name="SQL_ERROR"
		class="com.xxx.xxx.xxx.xxx.log.TimeSizeRollingFileAppender">
		<param name="File" value="uspc/sql/error.log" />
		<param name="MaxBackupIndex" value="300" />
		<param name="Encoding" value="GB2312" />
		<param name="MaxFileSize" value="50MB" />
		<param name="DatePattern" value="'.'yyyy-MM-dd" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern"
				value="%d{ISO8601} %p [%c] - [%m]%n" />
		</layout>
		<filter class="org.apache.log4j.varia.LevelRangeFilter">
			<param name="LevelMin" value="error" />
			<param name="LevelMax" value="error" />
			<param name="acceptOnMatch" value="true" />
		</filter>
	</appender>
中间省略其他appender配置
	<logger name="com.ibatis" additivity="false">
		<level value="info" />
		<appender-ref ref="SQL_DEBUG" />
		<appender-ref ref="SQL_INFO" />
		<appender-ref ref="SQL_ERROR" />
		<!--<appender-ref ref="console" />-->
	</logger>
	<logger name="org.mybatis" additivity="false">
		<level value="info" />
		<appender-ref ref="SQL_DEBUG" />
		<appender-ref ref="SQL_INFO" />
		<appender-ref ref="SQL_ERROR" />
		<!--<appender-ref ref="console" />-->
	</logger>
	<logger name="java.sql" additivity="false">
		<level value="info" />
		<appender-ref ref="SQL_DEBUG" />
		<appender-ref ref="SQL_INFO" />
		<appender-ref ref="SQL_ERROR" />
		<!--<appender-ref ref="console" />-->
	</logger>
	<logger name="com.xxx" additivity="false">
		<level value="info" />
		<!--<appender-ref ref="console" />-->
		<appender-ref ref="simsuspcDebug" />
		<appender-ref ref="simsuspcInfo" />
		<appender-ref ref="simsuspcError" />
	</logger>
	<logger name="org.quartz" additivity="false">
		<level value="info" />
		<appender-ref ref="QUARTZ_DEBUG" />
		<appender-ref ref="QUARTZ_INFO" />
		<appender-ref ref="QUARTZ_ERROR" />
		<!--<appender-ref ref="console" />-->
	</logger>
	<root>
		<level value="info" />
		<appender-ref ref="console" />
		<appender-ref ref="OTHER_DEBUG" />
		<appender-ref ref="OTHER_INFO" />
		<appender-ref ref="OTHER_ERROR" />
	</root>
</log4j:configuration>

晃眼一看，<root>配置了名称为console的appender，但却没有打印出来，原因是要打印的包路径的<logger>要么没有配置<appender-ref ref="console" />，要么additivity="false"。
注意上面代码的<!--<appender-ref ref="console" />-->和additivity="false"，前者在logger标签被注释并且additivity配置为false，意味着这个logger对应的日志不会被打印到控制台并且不会把日志传递到root来进来打印。

解决方案

此处解决方案有两种

  1. 每个需要打印日志的logger配置，加上<appender-ref ref="console" />，这样可以将logger的日志单独打印
  2. 不配置<appender-ref ref="console" />也可以，但需要指定additivity=true，意思是日志传递到root标签打印，root配置了<appender-ref ref="console" />，因此会打印到控制台

Log4j源码分析

业务类打印日志，从logger.info()入手

关键行：第2行，打印入口

if (logger.isInfoEnabled()) {
   logger.info("重发操作结束。重发=" + id);
}

org.apache.log4j.Category.info()

继承关系：public class Logger extends Category{…}

关键行：第4行

	public void info(Object message) {
        if (!this.repository.isDisabled(20000)) {
            if (Level.INFO.isGreaterOrEqual(this.getEffectiveLevel())) {
                this.forcedLog(FQCN, Level.INFO, message, (Throwable)null);
            }

        }
    }

org.apache.log4j.Category.forcedLog()

关键行：第2行

 	protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) {
        this.callAppenders(new LoggingEvent(fqcn, this, level, message, t));
    }

org.apache.log4j.Category.callAppenders()

关键行：第7行
注意：c.aai的aai属性是org.apache.log4j.helpers.AppenderAttachableImpl类型，包含一个Vector类型的appenderList，这个就是我们logger或者root标签配置的appender列表

    public void callAppenders(LoggingEvent event) {
        int writes = 0;

        for(Category c = this; c != null; c = c.parent) {
            synchronized(c) {
                if (c.aai != null) {
                    writes += c.aai.appendLoopOnAppenders(event);
                }

                if (!c.additive) {
                    break;
                }
            }
        }

        if (writes == 0) {
            this.repository.emitNoAppenderWarning(this);
        }

    }

org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders()

关键行：第8行 appender.doAppend(event)

    public int appendLoopOnAppenders(LoggingEvent event) {
        int size = 0;
        if (this.appenderList != null) {
            size = this.appenderList.size();

            for(int i = 0; i < size; ++i) {
                Appender appender = (Appender)this.appenderList.elementAt(i);
                appender.doAppend(event);
            }
        }

        return size;
    }

org.apache.log4j.Appender.doAppend()

关键行：第10行

public interface Appender {
    void addFilter(Filter var1);

    Filter getFilter();

    void clearFilters();

    void close();

    void doAppend(LoggingEvent var1);

    String getName();

    void setErrorHandler(ErrorHandler var1);

    ErrorHandler getErrorHandler();

    void setLayout(Layout var1);

    Layout getLayout();

    void setName(String var1);

    boolean requiresLayout();
}

org.apache.log4j.AppenderSkeleton.doAppend()

关键行：第22行 this.append(event)

    public synchronized void doAppend(LoggingEvent event) {
        if (this.closed) {
            LogLog.error("Attempted to append to closed appender named [" + this.name + "].");
        } else if (this.isAsSevereAsThreshold(event.getLevel())) {
            Filter f = this.headFilter;

            while(true) {
                if (f != null) {
                    switch(f.decide(event)) {
                    case -1:
                        return;
                    case 0:
                        f = f.getNext();
                        continue;
                    case 1:
                        break;
                    default:
                        continue;
                    }
                }

                this.append(event);
                return;
            }
        }
    }

抽象类AppenderSkeleton继承Appender接口实现了doAppend方法逻辑，doAppend方法调用了自身的一个抽象方法this.append(event)，而这个抽象方法具体由AppenderSkeleton抽象类的子类来实现。
org.apache.log4j.Appender接口的体系如下图
记一次Log4j.xml配置不当，业务日志不打印到控制台的问题!!!

org.apache.log4j.WriterAppender.append()

关键行：第3行

public void append(LoggingEvent event) {
        if (this.checkEntryConditions()) {
            this.subAppend(event);
        }
    }

org.apache.log4j.WriterAppender.subAppend()

由上面的继承体系可以看出，控制台打印输出的ConsoleAppender是直接继承的WriterAppender来的，而ConsoleAppender并没有重写subAppend方法，因此最终打印输出的逻辑就在这个subAppend方法。
关键行：

    protected void subAppend(LoggingEvent event) {
        this.qw.write(super.layout.format(event));
        if (super.layout.ignoresThrowable()) {
            String[] s = event.getThrowableStrRep();
            if (s != null) {
                int len = s.length;

                for(int i = 0; i < len; ++i) {
                    this.qw.write(s[i]);
                    this.qw.write(Layout.LINE_SEP);
                }
            }
        }

        if (this.immediateFlush) {
            this.qw.flush();
        }

    }

由上面的代码可以看出，打印刷新缓冲区用的是this.qw，这个qw在这里是QuietWriter

    public void flush() {
        try {
            super.out.flush();
        } catch (IOException var2) {
            this.errorHandler.error("Failed to flush writer,", var2, 2);
        }

    }

记一次Log4j.xml配置不当，业务日志不打印到控制台的问题!!!

相关标签： log4j

上一篇： Java 中你的日志规范吗？

下一篇： 将SpringBoot项目配置到外部服务器上

推荐阅读