logger(三)log4j2简介及其实现原理

太过爱你忘了你带给我的痛 2023-08-17 15:42 131阅读 0赞

### 一、log4j2简介 ###

log4j2是log4j 1.x和logback的改进版，据说采用了一些新技术（无锁异步、等等），使得日志的吞吐量、性能比log4j 1.x提高10倍，并解决了一些死锁的bug，而且配置更加简单灵活

maven配置

<dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.9.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.9.1</version>
    </dependency>
    
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <version>2.9.1</version>
    </dependency>
    
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.9.1</version>
    </dependency>
    
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.25</version>

也可以配置starter

<dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-log4j2</artifactId>
    </dependency>

二、log4j2.xml配置

实现类在`log4j2.xml`配置文件中的标签名。

<?xml version="1.0" encoding="UTF-8"?>
    
    
    
    <configuration status="WARN" monitorInterval="30">
        <properties>
            <property name="server.port"></property>
        </properties>
    
        
        <appenders>
            
            <console name="Console" target="SYSTEM_OUT">
                
                <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%thread] %p %m%n"/>
            </console>
            
            <RollingFile name="RollingFile" filePattern="/data/log/tomcat${sys:server.port}/catalina.%d{yyyy-MM-dd}.log">
                
                <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
                <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%thread] %p %m%n"/>
                <Policies>
                    <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
                </Policies>
                <DirectWriteRolloverStrategy/>
            </RollingFile>
        </appenders>
        
        <loggers>
            
            <logger name="org.springframework" level="INFO"></logger>
            <logger name="org.mybatis" level="INFO"></logger>
            <root level="INFO">
                <appender-ref ref="Console"/>
                <appender-ref ref="RollingFile"/>
            </root>
        </loggers>
    </configuration>

简单说Appender就是一个管道，定义了日志内容的去向(保存位置)。

配置一个或者多个`Filter进行过滤```

配置`Layout`来控制日志信息的输出格式。

配置`Policies`以控制日志何时(When)进行滚动。

配置`Strategy`以控制日志如何(How)进行滚动。

简单说了下配置项，具体可参考博客：[https://www.imooc.com/article/78966][https_www.imooc.com_article_78966]

[https://www.cnblogs.com/hafiz/p/6170702.html][https_www.cnblogs.com_hafiz_p_6170702.html]

### 三、log4j2其实现原理 ###

首先介绍下log4j2中的几个重要的概念

**LoggerContext**

LoggerContext在Logging System中扮演了锚点的角色。根据情况的不同，一个应用可能同时存在于多个有效的LoggerContext中。在同一LoggerContext下，log system是互通的。如：Standalone Application、Web Applications、Java EE Applications、”Shared” Web Applications 和REST Service Containers，就是不同广度范围的log上下文环境。

**Configuration**

每一个LoggerContext都有一个有效的Configuration。Configuration包含了所有的Appenders、上下文范围内的过滤器、LoggerConfigs以及StrSubstitutor.的引用。在重配置期间，新与旧的Configuration将同时存在。当所有的Logger对象都被重定向到新的Configuration对象后，旧的Configuration对象将被停用和丢弃。

** Logger**

Loggers 是通过调用LogManager.getLogger方法获得的。Logger对象本身并不实行任何实际的动作。它只是拥有一个name 以及与一个LoggerConfig相关联。它继承了AbstractLogger类并实现了所需的方法。当Configuration改变时，Logger将会与另外的LoggerConfig相关联，从而改变这个Logger的行为。

**LoggerConfig**

每个LoggerConfig和logger是对应的，获取到一个logger，写日志时其实是通过LoggerConfig来记日志的

#### 1、获取LoggerFactory ####

和logback一样，slf4j委托具体实现框架的StaticLoggerBinder来返回一个ILoggerFactory，从而对接到具体实现框架上，我们看下这个类(省略了部分代码)

public final class StaticLoggerBinder implements LoggerFactoryBinder {
    
        private static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder();
        private final ILoggerFactory loggerFactory;
    
        /**
         * Private constructor to prevent instantiation
         */
        private StaticLoggerBinder() {
            loggerFactory = new Log4jLoggerFactory();
        }
    
        /**
         * Returns the singleton of this class.
         *
         * @return the StaticLoggerBinder singleton
         */
        public static StaticLoggerBinder getSingleton() {
            return SINGLETON;
        }
    
        /**
         * Returns the factory.
         * @return the factor.
         */
        @Override
        public ILoggerFactory getLoggerFactory() {
            return loggerFactory;
        }
    }

可以看到

*  1、通过getSingleton()获取该类的单例
 *  2、通过构造函数新建了Log4jLoggerFactory实例，
 *  3、通过getLoggerFactory()方法返回该实例

#### 2、获取logger ####

进入Log4jLoggerFactory类中查看getLogger()方法，发现是在AbstractLoggerAdapter类中

@Override
        public L getLogger(final String name) {
            final LoggerContext context = getContext();
            final ConcurrentMap<String, L> loggers = getLoggersInContext(context);
            final L logger = loggers.get(name);
            if (logger != null) {
                return logger;
            }
            loggers.putIfAbsent(name, newLogger(name, context));
            return loggers.get(name);
        }

1、通过getContext()得到LoggerContext实例

2、在context中查找是否已经有该logger，有就返回

3、如果没有则调用newLogger(name, context)方法新建logger

Log4jLoggerFactory只有两个方法，就是上面说的getContext()和newLogger(name, context)。下面分两节分别讲下这两个方法

public class Log4jLoggerFactory extends AbstractLoggerAdapter<Logger> implements ILoggerFactory {
    
        private static final String FQCN = Log4jLoggerFactory.class.getName();
        private static final String PACKAGE = "org.slf4j";
    
        @Override
        protected Logger newLogger(final String name, final LoggerContext context) {
            final String key = Logger.ROOT_LOGGER_NAME.equals(name) ? LogManager.ROOT_LOGGER_NAME : name;
            return new Log4jLogger(context.getLogger(key), name);
        }
    
        @Override
        protected LoggerContext getContext() {
            final Class<?> anchor = StackLocatorUtil.getCallerClass(FQCN, PACKAGE);
            return anchor == null ? LogManager.getContext() : getContext(StackLocatorUtil.getCallerClass(anchor));
        }
    
    }

##### 2.1  getContext() #####

getContext()方法就是返回合适的loggerContext，进入LogManager.getContext()方法

public static LoggerContext getContext() {
            try {
                return factory.getContext(FQCN, null, null, true);
            } catch (final IllegalStateException ex) {
                LOGGER.warn(ex.getMessage() + " Using SimpleLogger");
                return new SimpleLoggerContextFactory().getContext(FQCN, null, null, true);
            }
        }

factory实在LoggerContext静态代码块中初始化的，继续进入factory.getContext(FQCN, null, null, true)方法中，进入实现类Log4jContextFactory中

@Override
        public LoggerContext getContext(final String fqcn, final ClassLoader loader, final Object externalContext,
                                        final boolean currentContext) {
            final LoggerContext ctx = selector.getContext(fqcn, loader, currentContext);
            if (externalContext != null && ctx.getExternalContext() == null) {
                ctx.setExternalContext(externalContext);
            }
            if (ctx.getState() == LifeCycle.State.INITIALIZED) {
                ctx.start();
            }
            return ctx;
        }

LoggerContext是从selector.getContext(fqcn, loader, currentContext)中获取的，此时判断ctx.getState()是否等于LifeCycle.State.INITIALIZED，第一次调用getlogger()时，会进入此方法，我们看下ctx.start();

public void start() {
            LOGGER.debug("Starting LoggerContext[name={}, {}]...", getName(), this);
            if (PropertiesUtil.getProperties().getBooleanProperty("log4j.LoggerContext.stacktrace.on.start", false)) {
                LOGGER.debug("Stack trace to locate invoker",
                        new Exception("Not a real error, showing stack trace to locate invoker"));
            }
            if (configLock.tryLock()) {
                try {
                    if (this.isInitialized() || this.isStopped()) {
                        this.setStarting();
                        reconfigure(); if (this.configuration.isShutdownHookEnabled()) {
                            setUpShutdownHook();
                        }
                        this.setStarted();
                    }
                } finally {
                    configLock.unlock();
                }
            }
            LOGGER.debug("LoggerContext[name={}, {}] started OK.", getName(), this);
        }

进入reconfigure()方法

private void reconfigure(final URI configURI) {
            final ClassLoader cl = ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null;
            LOGGER.debug("Reconfiguration started for context[name={}] at URI {} ({}) with optional ClassLoader: {}",
                    contextName, configURI, this, cl);
            final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(this, contextName, configURI, cl);
            if (instance == null) {
                LOGGER.error("Reconfiguration failed: No configuration found for '{}' at '{}' in '{}'", contextName, configURI, cl);
            } else {
                setConfiguration(instance);
                /*
                 * instance.start(); Configuration old = setConfiguration(instance); updateLoggers(); if (old != null) {
                 * old.stop(); }
                 */
                final String location = configuration == null ? "?" : String.valueOf(configuration.getConfigurationSource());
                LOGGER.debug("Reconfiguration complete for context[name={}] at URI {} ({}) with optional ClassLoader: {}",
                        contextName, location, this, cl);
            }
        }

我们的配置文件log4j2.xml就是该函数中实现的，ConfigurationFactory.getInstance().getConfiguration(this, contextName, configURI, cl)得到了配置文件，并解析成Configuration。进入setConfiguration(instance)方法，启动当前的configuration，并启动该配置下的所有appender，logger和root。

public Configuration setConfiguration(final Configuration config) {
            if (config == null) {
                LOGGER.error("No configuration found for context '{}'.", contextName);
                // No change, return the current configuration.
                return this.configuration;
            }
            configLock.lock();
            try {
                final Configuration prev = this.configuration;
                config.addListener(this);
                final ConcurrentMap<String, String> map = config.getComponent(Configuration.CONTEXT_PROPERTIES);
                try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadException
                    map.putIfAbsent("hostName", NetUtils.getLocalHostname());
                } catch (final Exception ex) {
                    LOGGER.debug("Ignoring {}, setting hostName to 'unknown'", ex.toString());
                    map.putIfAbsent("hostName", "unknown");
                }
                map.putIfAbsent("contextName", contextName);
                config.start(); this.configuration = config;
                updateLoggers();
                if (prev != null) {
                    prev.removeListener(this);
                    prev.stop();
                }
                firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config));
                try {
                    Server.reregisterMBeansAfterReconfigure();
                } catch (final LinkageError | Exception e) {
                    // LOG4J2-716: Android has no java.lang.management
                    LOGGER.error("Could not reconfigure JMX", e);
                }
                // AsyncLoggers update their nanoClock when the configuration changes
                Log4jLogEvent.setNanoClock(configuration.getNanoClock());
    
                return prev;
            } finally {
                configLock.unlock();
            }
        }

##### 2.2 newLogger(name, context) #####

protected Logger newLogger(final String name, final LoggerContext context) {
            final String key = Logger.ROOT_LOGGER_NAME.equals(name) ? LogManager.ROOT_LOGGER_NAME : name;
            return new Log4jLogger(context.getLogger(key), name);
        }

进入context.getLogger(key)方法

@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);
        }

进入newInstance(this, name, messageFactory)方法

protected Logger newInstance(final LoggerContext ctx, final String name, final MessageFactory messageFactory) {
            return new Logger(ctx, 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;
            }

public LoggerConfig getLoggerConfig(final String loggerName) {
            LoggerConfig loggerConfig = loggerConfigs.get(loggerName);
            if (loggerConfig != null) {
                return loggerConfig;
            }
            String substr = loggerName;
            while ((substr = NameUtil.getSubName(substr)) != null) {
                loggerConfig = loggerConfigs.get(substr);
                if (loggerConfig != null) {
                    return loggerConfig;
                }
            }
            return root;
        }

可以看到首先从loggerConfigs也就是配置文件中配置的logger中获取，如果获取不到则循环递归name中"."之前的logger，如果还是获取不到，则默认使用root的配置。

#### 3、logger.info() ####

Log4jLogger.class

public void info(final String format) {
            logger.logIfEnabled(FQCN, Level.INFO, null, format);
        }

@Override
        public void logIfEnabled(final String fqcn, final Level level, final Marker marker, final String message) {
            if (isEnabled(level, marker, message)) {
                logMessage(fqcn, level, marker, message);
            }
        }
    
     public boolean isEnabled(final Level level, final Marker marker, final String message) {
            return privateConfig.filter(level, marker, message);
        }
    
    protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message) {
            final Message msg = messageFactory.newMessage(message);
            logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
        }

可以看到isEnabled()方法中用来通过配置的filter来判断是否符合，如果符合则进入logMessage()方法

protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message) {
            final Message msg = messageFactory.newMessage(message);
            logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
        }
    
    private void logMessageSafely(final String fqcn, final Level level, final Marker marker, final Message msg,
                final Throwable throwable) {
            try {
                logMessageTrackRecursion(fqcn, level, marker, msg, throwable);
            } finally {
                // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())
                ReusableMessageFactory.release(msg);
            }
        }
    
    private void logMessageTrackRecursion(final String fqcn,
                                              final Level level,
                                              final Marker marker,
                                              final Message msg,
                                              final Throwable throwable) {
            try {
                incrementRecursionDepth(); // LOG4J2-1518, LOG4J2-2031
     tryLogMessage(fqcn, level, marker, msg, throwable);
            } finally {
                decrementRecursionDepth();
            }
        }

private void tryLogMessage(final String fqcn,
                                   final Level level,
                                   final Marker marker,
                                   final Message msg,
                                   final Throwable throwable) {
            try {
                logMessage(fqcn, level, marker, msg, throwable);
            } catch (final Exception e) {
                // LOG4J2-1990 Log4j2 suppresses all exceptions that occur once application called the logger
                handleLogMessageException(e, fqcn, msg);
            }
        }

public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,
                final Throwable t) {
            final Message msg = message == null ? new SimpleMessage(Strings.EMPTY) : message;
            final ReliabilityStrategy strategy = privateConfig.loggerConfig.getReliabilityStrategy();
            strategy.log(this, getName(), fqcn, marker, level, msg, t);
        }

public void log(final Supplier<LoggerConfig> reconfigured, final String loggerName, final String fqcn, final Marker marker, final Level level,
                final Message data, final Throwable t) {
            loggerConfig.log(loggerName, fqcn, marker, level, data, t);
        }

public void log(final String loggerName, final String fqcn, final Marker marker, final Level level,
                final Message data, final Throwable t) {
            List<Property> props = null;
            if (!propertiesRequireLookup) {
                props = properties;
            } else {
                if (properties != null) {
                    props = new ArrayList<>(properties.size());
                    final LogEvent event = Log4jLogEvent.newBuilder()
                            .setMessage(data)
                            .setMarker(marker)
                            .setLevel(level)
                            .setLoggerName(loggerName)
                            .setLoggerFqcn(fqcn)
                            .setThrown(t)
                            .build();
                    for (int i = 0; i < properties.size(); i++) {
                        final Property prop = properties.get(i);
                        final String value = prop.isValueNeedsLookup() // since LOG4J2-1575
                                ? config.getStrSubstitutor().replace(event, prop.getValue()) //
                                : prop.getValue();
                        props.add(Property.createProperty(prop.getName(), value));
                    }
                }
            }
            final LogEvent logEvent = logEventFactory.createEvent(loggerName, marker, fqcn, level, data, props, t);
            try {
                log(logEvent, LoggerConfigPredicate.ALL);
            } finally {
                // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())
                ReusableLogEventFactory.release(logEvent);
            }
        }

protected void log(final LogEvent event, final LoggerConfigPredicate predicate) {
            if (!isFiltered(event)) {
               processLogEvent(event, predicate);
            }
        }

private void processLogEvent(final LogEvent event, final LoggerConfigPredicate predicate) {
            event.setIncludeLocation(isIncludeLocation());
            if (predicate.allow(this)) {
                callAppenders(event);
            }
            logParent(event, predicate);
        }
    
    protected void callAppenders(final LogEvent event) {
            final AppenderControl[] controls = appenders.get();
            //noinspection ForLoopReplaceableByForEach
            for (int i = 0; i < controls.length; i++) {
                controls[i].callAppender(event);
            }
        }

这时候终于到了appender的处理了，直接定位到RollingFileAppender类中

public void append(final LogEvent event) {
            getManager().checkRollover(event);
            super.append(event);
        }

private void tryAppend(final LogEvent event) {
            if (Constants.ENABLE_DIRECT_ENCODERS) {
                directEncodeEvent(event);
            } else {
                writeByteArrayToManager(event);
            }
        }
    protected void directEncodeEvent(final LogEvent event) {
            getLayout().encode(event, manager);
            if (this.immediateFlush || event.isEndOfBatch()) {
                manager.flush();
            }
        }

这时候可以看到layout和encode的使用了

public void encode(final StringBuilder source, final ByteBufferDestination destination) {
            try {
                final Object[] threadLocalState = getThreadLocalState();
                final CharsetEncoder charsetEncoder = (CharsetEncoder) threadLocalState[0];
                final CharBuffer charBuffer = (CharBuffer) threadLocalState[1];
                final ByteBuffer byteBuffer = (ByteBuffer) threadLocalState[2];
                TextEncoderHelper.encodeText(charsetEncoder, charBuffer, byteBuffer, source, destination);
            } catch (final Exception ex) {
                logEncodeTextException(ex, source, destination);
                TextEncoderHelper.encodeTextFallBack(charset, source, destination);
            }
        }

最后写日志。

### 四、通过代码动态生成logger对象 ###

public class LoggerHolder {
    
    
        //加个前缀防止配置的name正好是我们某个类名，导致使用的日志路径使用了类名的路径
        private static final String PREFIX = "logger_";
    
        /**
         * 支持生成写大数据文件的logger
         *
         * @param name logger name
         * @return Logger
         */
        public static Logger getLogger(String name) {
            String loggerName = PREFIX + name;
            Log4jLoggerFactory loggerFactory = (Log4jLoggerFactory) LoggerFactory.getILoggerFactory();
            LoggerContext context = (LoggerContext) LogManager.getContext();
            //如果未加载过该logger,则新建一个
            if (loggerFactory.getLoggersInContext(context).get(loggerName) == null) {
                buildLogger(name);
            }
            //
            return loggerFactory.getLogger(loggerName);
        }
    
        /**
         * 包装了Loggerfactory，和LoggerFactory.getLogger(T.class)功能一致
         *
         * @param clazz
         * @return
         */
        public static Logger getLogger(Class<?> clazz) {
            Log4jLoggerFactory loggerFactory = (Log4jLoggerFactory) LoggerFactory.getILoggerFactory();
            return loggerFactory.getLogger(clazz.getName());
        }
    
        /**
         * @param name logger name
         */
        private static void buildLogger(String name) {
            String loggerName = PREFIX + name;
            LoggerContext context = (LoggerContext) LogManager.getContext();
            Configuration configuration = context.getConfiguration();
            //配置PatternLayout输出格式
            PatternLayout layout = PatternLayout.newBuilder()
                    .withCharset(UTF_8)
                    .withPattern("%msg%n")
                    .build();
            //配置基于时间的滚动策略
            TimeBasedTriggeringPolicy policy = TimeBasedTriggeringPolicy.newBuilder()
                    .withInterval(24)
                    .build();
            //配置同类型日志策略
            DirectWriteRolloverStrategy strategy = DirectWriteRolloverStrategy.newBuilder()
                    .withConfig(configuration)
                    .build();
            //配置appender
            RollingFileAppender appender = RollingFileAppender.newBuilder()
                    .setName(loggerName)
                    .withFilePattern("/data/bigdata/" + name + "/" + name + ".%d{yyyyMMdd}.log")
                    .setLayout(layout)
                    .withPolicy(policy)
                    .withStrategy(strategy)
                    .withAppend(true)
                    .build();
            //改变appender状态
            appender.start();
            //新建logger
            LoggerConfig loggerConfig = new LoggerConfig(loggerName, Level.INFO, false);
            loggerConfig.addAppender(appender, Level.INFO, null);
            configuration.addLogger(loggerName, loggerConfig);
            context.updateLoggers();
        }
    }

转载于:https://www.cnblogs.com/pjfmeng/p/11277124.html

[https_www.imooc.com_article_78966]: https://www.imooc.com/article/78966
[https_www.cnblogs.com_hafiz_p_6170702.html]: https://www.cnblogs.com/hafiz/p/6170702.html