转载自:https://www.cnblogs.com/Anidot/articles/7744018.html
一、概述
slf4j(全称是Simple Loging Facade For Java)是一个为Java程序提供日志输出的统一接口,并不是一个具体的日志实现方案,就好像我们经常使用的JDBC一样,只是一种接口规则定义而已,使用了slf4j可以对客户端应用解耦。因为当我们在代码实现中引入log日志的时候,用的是接口,所以可以实时的更具情况来调换具体的日志实现类。这就是slf4j的作用。基于SLF4J日志实现方案,比如apache的log4j,log4j2,logback,jdk自带的java.util.logging.Logger等等。
其中对应的实现jar包:
slf4j-log4j12-x.x.x.jar/log4j-slf4j-impl是使用org.apache.log4j.Logger提供的驱动
slf4j-jdk14-x.x.x.jar是使用java.util.logging提供的驱动
slf4j-simple-x.x.x.jar直接绑定System.err
slf4j-jcl-x.x.x.jar是使用commons-logging提供的驱动
logback-classic-x.x.x.jar是使用logback提供的驱动
二、工作原理窥探
- 简单实现
1 package com.test.slf4j; 2 import org.slf4j.Logger; 3 import org.slf4j.LoggerFactory; 4 public class TestLog4j { 5 private static final Logger LOGGER = LoggerFactory.getLogger(TestLog4j.class); 6 7 public static void main(String[] args) { 8 String message = "服务器出错啦."; 9 LOGGER.info("Error message is: {}", message); 10 } 11 }
- 通过LoggerFactory类的静态getLogger()获取logger。slf4j-api作为slf4j的接口类,使用在程序代码中,这个包提供了一个Logger类和LoggerFactory类,Logger类用来打日志,LoggerFactory类用来获取Logger;比如说:slf4j-log4j,这个包是连接slf4j和log4j的桥梁,怎么连接的呢?我们看看slf4j的LoggerFactory类的getLogger函数的源码:
public static Logger getLogger(String name) { ILoggerFactory iLoggerFactory = getILoggerFactory(); return iLoggerFactory.getLogger(name); } public static ILoggerFactory getILoggerFactory() { if (INITIALIZATION_STATE == UNINITIALIZED) { synchronized (LoggerFactory.class) { if (INITIALIZATION_STATE == UNINITIALIZED) { INITIALIZATION_STATE = ONGOING_INITIALIZATION; performInitialization(); } } } switch (INITIALIZATION_STATE) { case SUCCESSFUL_INITIALIZATION: return StaticLoggerBinder.getSingleton().getLoggerFactory(); // StaticLoggerBinder非SLF4J提供,是由具体的实现包,如log4j,logback来提供 case NOP_FALLBACK_INITIALIZATION: return NOP_FALLBACK_FACTORY; case FAILED_INITIALIZATION: throw new IllegalStateException(UNSUCCESSFUL_INIT_MSG); case ONGOING_INITIALIZATION: // support re-entrant behavior. // See also http://jira.qos.ch/browse/SLF4J-97 return SUBST_FACTORY; } throw new IllegalStateException("Unreachable code"); }
- 我本地同时引入了log4j2和logback包,即可看到实现。可以看出log4j-slf4j提供了该org.slf4j.impl.StaticLoggerBinder静态类来实现slf4和log4j的桥接
- 再看看slf4j-log4j包种的这个StaticLoggerBinder类创建ILoggerFactory长什么样子
package org.slf4j.impl; import org.apache.logging.slf4j.Log4jLoggerFactory; import org.slf4j.ILoggerFactory; import org.slf4j.spi.LoggerFactoryBinder; public final class StaticLoggerBinder implements LoggerFactoryBinder { public static String REQUESTED_API_VERSION = "1.6"; private static final String LOGGER_FACTORY_CLASS_STR = Log4jLoggerFactory.class.getName(); private static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder(); private final ILoggerFactory loggerFactory = new Log4jLoggerFactory(); private StaticLoggerBinder() { } public static StaticLoggerBinder getSingleton() { return SINGLETON; } public ILoggerFactory getLoggerFactory() { return this.loggerFactory; } public String getLoggerFactoryClassStr() { return LOGGER_FACTORY_CLASS_STR; } }
-
可以看到slf4j-log4j中的StaticLoggerBinder类创建的ILoggerFactory其实是一个org.slf4j.impl.Log4jLoggerFactory,这个类的getLogger函数代码如下:
package org.apache.logging.slf4j; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.spi.AbstractLoggerAdapter; import org.apache.logging.log4j.spi.LoggerContext; import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.slf4j.Log4jLogger; import org.slf4j.ILoggerFactory; import org.slf4j.Logger; public class Log4jLoggerFactory extends AbstractLoggerAdapter<Logger> implements ILoggerFactory { private static final String FQCN = Log4jLoggerFactory.class.getName(); private static final String PACKAGE = "org.slf4j"; public Log4jLoggerFactory() { } protected Logger newLogger(String name, LoggerContext context) { String key = "ROOT".equals(name)?"":name; return new Log4jLogger(context.getLogger(key), name); } protected LoggerContext getContext() { Class anchor = StackLocatorUtil.getCallerClass(FQCN, "org.slf4j"); return anchor == null?LogManager.getContext():this.getContext(StackLocatorUtil.getCallerClass(anchor)); } }
三、slf4j加载实现类顺序问题
- 默认来说,slf4j的加载实现类是随机的,如发现有多个org.slf4j.impl.StaticLoggerBinder,启动应用的时候会出现下面警告:
- 从源码上来看,在getILoggerFactory()方法中,初始化会调用performInitialization方法进行检测实现类,最终会调用
reportMultipleBindingAmbiguity方法打印出警告信息
static Set<URL> findPossibleStaticLoggerBinderPathSet() { Set<URL> staticLoggerBinderPathSet = new LinkedHashSet<URL>(); try { ClassLoader loggerFactoryClassLoader = LoggerFactory.class.getClassLoader(); Enumeration<URL> paths; if (loggerFactoryClassLoader == null) { paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH); } else { paths = loggerFactoryClassLoader.getResources(STATIC_LOGGER_BINDER_PATH); } while (paths.hasMoreElements()) { URL path = paths.nextElement(); staticLoggerBinderPathSet.add(path); } } catch (IOException ioe) { Util.report("Error getting resources from path", ioe); } return staticLoggerBinderPathSet; } private static void reportMultipleBindingAmbiguity(Set<URL> binderPathSet) { if (isAmbiguousStaticLoggerBinderPathSet(binderPathSet)) { Util.report("Class path contains multiple SLF4J bindings."); for (URL path : binderPathSet) { Util.report("Found binding in [" + path + "]"); } Util.report("See " + MULTIPLE_BINDINGS_URL + " for an explanation."); } } private static void reportActualBinding(Set<URL> binderPathSet) { // binderPathSet can be null under Android if (binderPathSet != null && isAmbiguousStaticLoggerBinderPathSet(binderPathSet)) { Util.report("Actual binding is of type [" + StaticLoggerBinder.getSingleton().getLoggerFactoryClassStr() + "]"); } }
四、log4j2简单例子
- log4j2的MDC配置
public final class ContextLog4j2Util { /** * 将上下文环境变量信息加入到MDC中,以便打印到日志 */ public static void addContext2MDC() { MDC.put(ContextConstKey.REQUEST_NO, StringUtils.isEmpty(context.getRequestNo()) ? "" : context.getRequestNo()); MDC.put(ContextConstKey.CONSUMER_IP, StringUtils.isEmpty(context.getConsumerIp()) ? "" : context.getConsumerIp()); MDC.put(ContextConstKey.CHANNEL_CODE, StringUtils.isEmpty(context.getChannelCode()) ? "" : context.getChannelCode()); MDC.put(ContextConstKey.LOCAL_IP, NetUtils.getLocalHost()); } /** * 从MDC清理对象 */ public static void removeContextFromMDC() { MDC.remove(ContextConstKey.REQUEST_NO); MDC.remove(ContextConstKey.CONSUMER_IP); MDC.remove(ContextConstKey.CHANNEL_CODE); MDC.remove(ContextConstKey.REMOTE_IP); MDC.remove(ContextConstKey.LOCAL_IP); } }
- log4j2.xml配置
<?xml version="1.0" encoding="UTF-8"?> <configuration status="WARN" shutdownHook="disable"> <Properties> <Property name="sysName">test-app</Property> <Property name="bizLogLevel">INFO</Property> <Property name="otherLogLevel">INFO</Property> <Property name="logFilePath">/home/q/test/test-app/logs</Property> <Property name="logSize">1000 MB</Property> <Property name="maxFile">100</Property> <Property name="errorLogFile">${sysName}_err</Property> <Property name="bizLogFile">${sysName}_biz</Property> <Property name="allLogFile">${sysName}_all</Property> <Property name="monitorLogFile">${sysName}_monitor</Property> <Property name="ioLogFile">${sysName}_io</Property> <Property name="dcLogFile">${sysName}_dc</Property> <Property name="rdsLogFile">${sysName}_rds</Property> <Property name="threadLogFile">${sysName}_thread</Property> <Property name="tempLogFile">${sysName}_temp</Property> </Properties> <appenders> <Console name="Console" target="SYSTEM_OUT"> <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> </Console> <RollingFile name="ErrorRollingFile" fileName="${logFilePath}/${errorLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${errorLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="BizRollingFile" fileName="${logFilePath}/${bizLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${bizLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Filters> <ThresholdFilter level="${bizLogLevel}"/> <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/> </Filters> <Policies> <TimeBasedTriggeringPolicy /> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="AllRollingFile" fileName="${logFilePath}/${allLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${allLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="MonitorRollingFile" fileName="${logFilePath}/${monitorLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${monitorLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout pattern="%date{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%msg%n"/> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="IORollingFile" fileName="${logFilePath}/${ioLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${ioLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Filters> <ThresholdFilter level="${bizLogLevel}"/> <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/> </Filters> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="DcRollingFile" fileName="${logFilePath}/${dcLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${dcLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Filters> <ThresholdFilter level="${bizLogLevel}"/> </Filters> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="RdsRollingFile" fileName="${logFilePath}/${rdsLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${rdsLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Filters> <ThresholdFilter level="${bizLogLevel}"/> </Filters> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="ThreadRollingFile" fileName="${logFilePath}/${threadLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${threadLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout pattern="%date{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%msg%n"/> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <RollingFile name="TempRollingFile" fileName="${logFilePath}/${tempLogFile}.log" filePattern="${logFilePath}/$${date:yyyy-MM}/${tempLogFile}-%d{MM-dd-yyyy}-%i.log.gz"> <PatternLayout charset="UTF-8" pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t] [%X{requestNo}|%X{consumerIp}|%X{sysChannelCode}|%X{localIp}] [%c:%line] - %msg%n"/> <Filters> <ThresholdFilter level="${bizLogLevel}"/> <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/> </Filters> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="${logSize}"/> </Policies> <DefaultRolloverStrategy max="${maxFile}"/> </RollingFile> <CatAppender name="CatAppender"/> </appenders> <loggers> <logger name="com.app.msf.core.annotation.log.InputOutputLogger" level="${bizLogLevel}" additivity="false"> <appender-ref ref="IORollingFile"/> </logger> <logger name="com.app.msf.core.annotation.log" level="${bizLogLevel}" additivity="false"> <appender-ref ref="MonitorRollingFile"/> </logger> <logger name="com.app.test" level="${bizLogLevel}" additivity="false"> <appender-ref ref="ErrorRollingFile" /> <appender-ref ref="BizRollingFile"/> <appender-ref ref="CatAppender"/> </logger> <logger name="com.app.msf.rmq.consumer.impl.ConsumerServiceImpl" level="${bizLogLevel}" additivity="false"> <appender-ref ref="BizRollingFile"/> <appender-ref ref="AllRollingFile"/> </logger> <logger name="com.app.test.modules.cust.dao" level="DEBUG" additivity="false"> <appender-ref ref="ErrorRollingFile" /> <appender-ref ref="BizRollingFile"/> <appender-ref ref="CatAppender"/> </logger> <logger name="com.app.test.modules.user.dao" level="DEBUG" additivity="false"> <appender-ref ref="ErrorRollingFile" /> <appender-ref ref="BizRollingFile"/> <appender-ref ref="CatAppender"/> </logger> <logger name="com.app.msf.threadpool" level="${bizLogLevel}" additivity="false"> <appender-ref ref="ThreadRollingFile"/> </logger> <logger name="com.alibaba.dubbo.common.threadpool" level="${bizLogLevel}" additivity="false"> <appender-ref ref="ThreadRollingFile"/> </logger> <logger name="tempLog" level="${bizLogLevel}" additivity="false"> <appender-ref ref="TempRollingFile"/> </logger> <root level="${otherLogLevel}"> <appender-ref ref="AllRollingFile"/> <appender-ref ref="ErrorRollingFile"/> <appender-ref ref="CatAppender"/> </root> </loggers> </configuration>
五、工作中遇到的问题
在生产上web应用中,catalina.out文件打印了DEBUG日志,经发现是因为包冲突,spring框架选用了slf4j的logback日志实现导致的。
两个方案:
- 添加logback的日志配置文件,默认为warn
- 排除logback实现包,但是以后新加包也可能会间接依赖导致问题再次发生(不使用该方案,slf4j的实现包太多,很容易被间接依赖,所以不仅仅是排除logback的实现)
- logback的空实现
<?xml version="1.0" encoding="UTF-8"?> <configuration debug="false"> <!-- 控制台输出 --> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"> <!--格式化输出:%d表示日期,%thread表示线程名,%-5level:级别从左显示5个字符宽度%msg:日志消息,%n是换行符--> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern> </encoder> </appender> <!-- 日志输出级别 --> <root level="WARN"> <appender-ref ref="STDOUT"/> </root> </configuration> <!-- ************************************************************* --> <!-- ************************************************************* --> <!-- ************************************************************* --> <!-- logback空配置文件防止应用把日志打印到console:******************* --> <!-- 1,web应用的catalina.out************************************** --> <!-- 2,app应用的启动脚本stdout.log********************************* --> <!-- ************************************************************* --> <!-- ************************************************************* --> <!-- ************************************************************* -->