业务开发中,少不了打印日志,常用的日志框架有commons logging/log4j/logback/log4j2等,同步日志方面logback性能略微胜出,而异步日志方面log4j2性能突出。今天我们就聊聊Logback。
SLF4J
说到logback,必会提及slf4j。slf4j的全称是:The Simple Logging Facade for Java,是java的一个日志门面,堪称Facade设计模式的最佳代言人!slf4j制定了一套标准接口,从而实现在【日志】这个领域里一统江湖。主要做两件事:
- 实现了Logger获取的通用api:LoggreFactory.getLogger(),该方法基本上确定了获取Logger的基础套路,约定了实现slf4j的日志框架需要实现org.slf4j.impl.StaticLoggerBinder,完成与slf4j的集成。
- 定义了ILoggerFactory,Logger等系列接口,该接口由具体日志框架实现。
这种通用API使得我们在切换日志框架时显得非常轻松,仅仅需要改一下依赖的jar包,而不需要修改任何日志相关的代码。slf4J抽象了统一的日志接口,而logback等是具体的日志框架,其原生实现了slf4j。而其它日志框架(log4j/commons logging等)需要通过适配,才能实现与slf4j的集成。
LoggerFactory.getLogger()
在slf4j的标准里,获取Logger通过LoggerFactory.getLogger(),这里的LoggerFactory是slf4j实现的,我们进入源码:
public static Logger getLogger(String name) {
ILoggerFactory iLoggerFactory = getILoggerFactory();
return iLoggerFactory.getLogger(name);
}
该方法主要做两件事,一是获取(创建)ILoggerFactory,二是通过ILoggerFactory获取(创建)Logger对象
LoggerContext初始化
在logback里,实现ILoggerFactory的是LoggerContext,该类是logback的核心所在,有点类似于spring的ApplicationContext。来看看它的主要成员:
final Logger root;
private int size;
private int noAppenderWarning = 0;
final private List<LoggerContextListener> loggerContextListenerList = new ArrayList<LoggerContextListener>();
private Map<String, Logger> loggerCache;
private LoggerContextVO loggerContextRemoteView;
private final TurboFilterList turboFilterList = new TurboFilterList();
private boolean packagingDataEnabled = DEFAULT_PACKAGING_DATA;
private int maxCallerDataDepth = ClassicConstants.DEFAULT_MAX_CALLEDER_DATA_DEPTH;
int resetCount = 0;
private List<String> frameworkPackages;
其中最核心的是:
loggerCache:维护着已创建好的Logger对象实例,
root:根Logger,没错,就是那个配置文件里的那个所对应的Logger
通过这个定义大概可以看出,LoggerContext具备管理Logger的能力,回过头来看getILoggerFactory()的实现:
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();
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");
}
SLF4J定义了LoggerFactory的几个状态,在这几个状态下,会返回不同的ILoggerFactory:
状态 | 状态描述 | 对应的ILoggerFactory | 说明 |
SUCCESSFUL_INITIALIZATION | 初始化成功 | LoggerContext | 由具体日志框架(logback)实现 |
FAILED_INITIALIZATION | 初始化失败 | 抛出异常 | |
NOP_FALLBACK_INITIALIZATION | 不作为 | NOPLoggerFactory | SLF4J实现,不对日志做任务处理 |
ONGOING_INITIALIZATION | 初始化中 | SubstituteLoggerFactory | SLF4J实现,用于生产可被代替的Logger |
其中ONGOING_INITIALIZATION是个有趣的状态,在这个状态下,会返回一个SUBST_FACTORY,这是个SubstituteLoggerFactory,用于生产SubstituteLogger(同样实现了Logger接口),这种类型Logger不是正式的Logger,其持有一个正式Logger的引用,该引用在初始化为null,等到正式的LoggerFactory(即LoggerContext)初始化成功之后,框架会将正式Logger的引用赋值给SubstituteLogger,得益于这种设计,业务系统的启动速度不会受到Logback自身初始化的丝毫影响。
接着来看performInitialization():
private final static void performInitialization() {
bind();
if (INITIALIZATION_STATE == SUCCESSFUL_INITIALIZATION) {
versionSanityCheck();
}
}
来到bind(),这个方法很重要,基本上可以窥探整个初始化流程。主要做以下几件事:
private final static void bind() {
try {
//1:查找并获取StaticLoggerBinder的类路径
Set<URL> staticLoggerBinderPathSet = null;
if (!isAndroid()) {
staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
}
//2:初始化
StaticLoggerBinder.getSingleton();
//3:标记初始化完成
INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
//4:告诉客户:真实绑定了哪个StaticLoggerBinder
reportActualBinding(staticLoggerBinderPathSet);
//5:修正SubstituteLogger,将真正的Logger赋值给SubstituteLogger
fixSubstituteLoggers();
//6:对SubstituteLogger所记录的SubstituteLoggerEvent做真正的记录
replayEvents();
//7:SubstituteLoggerFactory已完成使命,清空
SUBST_FACTORY.clear();
} catch (NoClassDefFoundError ncde) {
String msg = ncde.getMessage();
if (messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) {
INITIALIZATION_STATE = NOP_FALLBACK_INITIALIZATION;
Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\".");
Util.report("Defaulting to no-operation (NOP) logger implementation");
Util.report("See " + NO_STATICLOGGERBINDER_URL + " for further details.");
} else {
failedBinding(ncde);
throw ncde;
}
} catch (java.lang.NoSuchMethodError nsme) {
String msg = nsme.getMessage();
if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) {
INITIALIZATION_STATE = FAILED_INITIALIZATION;
Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding.");
Util.report("Your binding is version 1.5.5 or earlier.");
Util.report("Upgrade your binding to version 1.6.x.");
}
throw nsme;
} catch (Exception e) {
failedBinding(e);
throw new IllegalStateException("Unexpected initialization failure", e);
}
}
SLF4J先找到可能的StaticLoggerBinder,然后调用第1个StaticLoggerBinder的getSingleton()方法. StaticLoggerBinder使用单例模式,其对象的实例化过程就是logback 的初始化过程。这里不一一贴出代码,大概过程如下:
1. 查找logback配置文件 ,以logback1.2.3为例,优先找logback.groovy,logback-text.xml次之,最后找logback.xml
2. 使用sax解释并加载配置,将每个元素解释为一个SaxEvent对象,然后交给EventPlayer进行事件播放(即配置解释),最后根据元素的路径(ElementPath)会匹配到一个以上的Action(元素与Action的对象关系维护在JoranConfigurator中),而Action执行最终的解释,并最终生成Logger,Appender,Encodor,Layout等序列对象。
如AppenderAction负责解释元素,生成Appender对象,LoggerAction对象负责解释元素,生成Logger对象等。下面以LoggerAction为例进行分析:
public void begin(InterpretationContext ec, String name, Attributes attributes) {
// Let us forget about previous errors (in this object)
inError = false;
logger = null;
LoggerContext loggerContext = (LoggerContext) this.context;
//拿<logger>中的name属性
String loggerName = ec.subst(attributes.getValue(NAME_ATTRIBUTE));
//name不能为空
if (OptionHelper.isEmpty(loggerName)) {
inError = true;
String aroundLine = getLineColStr(ec);
String errorMsg = "No 'name' attribute in element " + name + ", around " + aroundLine;
addError(errorMsg);
return;
}
//通过LoggerContext.getLogger()
logger = loggerContext.getLogger(loggerName);
//解释并设置level属性
String levelStr = ec.subst(attributes.getValue(LEVEL_ATTRIBUTE));
if (!OptionHelper.isEmpty(levelStr)) {
if (ActionConst.INHERITED.equalsIgnoreCase(levelStr) || ActionConst.NULL.equalsIgnoreCase(levelStr)) {
addInfo("Setting level of logger [" + loggerName + "] to null, i.e. INHERITED");
logger.setLevel(null);
} else {
Level level = Level.toLevel(levelStr);
addInfo("Setting level of logger [" + loggerName + "] to " + level);
logger.setLevel(level);
}
}
//解释并设置additive属性
String additivityStr = ec.subst(attributes.getValue(ActionConst.ADDITIVITY_ATTRIBUTE));
if (!OptionHelper.isEmpty(additivityStr)) {
boolean additive = OptionHelper.toBoolean(additivityStr, true);
addInfo("Setting additivity of logger [" + loggerName + "] to " + additive);
logger.setAdditive(additive);
}
ec.pushObject(logger);
}
Logger的创建
Logger的创建有两个时机,一个在配置文件中通过元素定义,经LoggerAction解释后生成,一个是通过LoggerFactory.getLogger(),无论哪一种,最终都会进入LoggerContext.getLogger()
@Override
public final Logger getLogger(final String name) {
if (name == null) {
throw new IllegalArgumentException("name argument cannot be null");
}
//如果请求的是根Logger,则直接返回
if (Logger.ROOT_LOGGER_NAME.equalsIgnoreCase(name)) {
return root;
}
int i = 0;
Logger logger = root;
//从缓存中拿Logger
Logger childLogger = (Logger) loggerCache.get(name);
if (childLogger != null) {
return childLogger;
}
//从ROOT开始,沿着name的方向,依次获取并创建Logger
String childName;
while (true) {
int h = LoggerNameUtil.getSeparatorIndexOf(name, i);
if (h == -1) {
childName = name;
} else {
childName = name.substring(0, h);
}
// move i left of the last point
i = h + 1;
synchronized (logger) {
childLogger = logger.getChildByName(childName);
if (childLogger == null) {
childLogger = logger.createChildByName(childName);
loggerCache.put(childName, childLogger);
incSize();
}
}
logger = childLogger;
if (h == -1) {
return childLogger;
}
}
}
通常元素中指定的name是包名,而getLogger()中指定的类名,logback会从root开始,尚着包名或类名的方向,以包为单位,逐级创建对应名称的Logger,比如:getLogger(“com.vip.aaa.bbb.HelloService”),会依次创建如下的Logger:
次序 | logger名称 |
1 | com |
2 | com.vip |
3 | com.vip.aaa |
4 | com.vip.aaa.bbb |
5 | com.vip.aaa.bbb.HelloService |
一个Logger有一个parent(根Logger除外),和若干个child,所有的Logger构成一棵Logger树。而这么Logger,一旦创建出来,就全部会缓存在LoggerContext的loggerCache中。
日志级别的继承
1个Logger如果没有显式指定level,其level由其parent决定,见Logger.createChildByName
Logger createChildByName(final String childName) {
int i_index = LoggerNameUtil.getSeparatorIndexOf(childName, this.name.length() + 1);
if (i_index != -1) {
throw new IllegalArgumentException("For logger [" + this.name + "] child name [" + childName
+ " passed as parameter, may not include '.' after index" + (this.name.length() + 1));
}
if (childrenList == null) {
childrenList = new CopyOnWriteArrayList<Logger>();
}
Logger childLogger;
childLogger = new Logger(childName, this, this.loggerContext);
childrenList.add(childLogger);
//子级logger的有效级别继承自直属的父级Logger
childLogger.effectiveLevelInt = this.effectiveLevelInt;
return childLogger;
}
Logger的打印
以最常用的Logger.info()为例,SLF4J推荐使用log.info(“hello {}”,变量名)方式来打印日志,可接受1个或多个变量。SLF4J定义了10个重载方法,在logback的实现中,最终会根据日志参数个数的不同,调用不同的方法:
0或者3个以上参数调用:filterAndLog_0_Or3Plus()
1个参数调用:filterAndLog_1()
2个参数调用:filterAndLog_2()
为什么这么做,文档中解释是:The next methods are not merged into one because of the time we gain by not creating a new Object[] with the params. This reduces the cost of not logging by about 20 nanoseconds.
分开多个方法,虽然代码看不去没那么优雅,但在日志不需要被记录(如达不到指定级别)的情况下,可以不需要创建参数数组,从而提升一点点性能(20纳秒)。进入:filterAndLog_0_Or3Plus()
private void filterAndLog_0_Or3Plus(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
final Throwable t) {
final FilterReply decision = loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
if (decision == FilterReply.NEUTRAL) {
if (effectiveLevelInt > level.levelInt) {
return;
}
} else if (decision == FilterReply.DENY) {
return;
}
buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
在LoggerContext中有个TurboFilterList,存放了若干个TurboFilter,用于在日志记录之前搞些事情,最终决定是否将这个日志放行,最会返回FilterReply,
DENY:表示拒绝,将抛弃这个日志请求。
NEUTRAL:放行,进入写一下TurboFilter
ACCEPT:接受,表示要定这个请求,跳过后面的TurboFilter,直接进入日志打印:buildLoggingEventAndAppend()
private void buildLoggingEventAndAppend(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
final Throwable t) {
LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);
le.setMarker(marker);
callAppenders(le);
}
调用Appender时,会逐级追溯父级Logger,并将LoggerEvent交给父级Logger的Appender去处理,直到logger.additive被配置为false。
public void callAppenders(ILoggingEvent event) {
int writes = 0;
for (Logger l = this; l != null; l = l.parent) {
writes += l.appendLoopOnAppenders(event);
if (!l.additive) {
break;
}
}
// No appenders in hierarchy
if (writes == 0) {
loggerContext.noAppenderDefinedWarning(this);
}
}
后面的代码,就是日志的格式化和输出,涉及到Encoder,Layout,Converter等,作者对各层组件(接口)做了很好的抽象,体现了很好的分层思想。具体的代码不一一展开,有兴趣的同学可以自己看看。主要的流程如下: