Logback 的架构
Logback的基本架构非常通用,可以在不同的情况下应用。目前,logback分为 logback-core、logback-classic 和 logback-access 三个模块。
核心模块为其他两个模块奠定了基础。classic 模块扩展了核心模块。classic 模块相当于是 log4j 的一个改进的版本。Logback classic 实现了 SLF4J API,因此您可以方便地在 Logback 和其他日志系统,如 log4j 或 在JDK1.4中引入的 java.util.logging (JUL) 之间来回切换。第三个名为 access 的模块与 Servlet 容器集成,以提供 HTTP 访问日志功能。另一个文档包含 access 模块文档。
在本文档的其余部分中,我们将用 “logback” 来指代 logback-classic 模块。
Logger, Appender 和 Layout
Logback 构建在三个主要类上:Logger、Appender 和 Layout。这三种类型的组件协同工作,使开发人员能够根据消息类型和级别记录消息,并在运行时控制这些消息的格式和报告位置。
Logger 类是 logback-classic 模块的一部分。另一方面,Appender 和 Layout 接口是 logback-core 的一部分。作为一个通用模块,logback-core 没有 Logger 的概念。
Logger 上下文
任何日志 API 相对于普通的 System.out.println 的首要优势就是,它能够禁用某些日志语句,同时允许其他语句不受阻碍地打印。 此功能假定日志空间,即所有可能的日志语句的空间,根据开发人员选择的一些标准进行分类。在 logback-classic 中,这种分类是记录器固有的一部分。每个记录器都连接到一个LoggerContext,该上下文负责制造记录器并将它们排列成树状层次结构。
记录器是命名实体。它们的名称区分大小写,并遵循分层命名规则:
命名层次结构
如果一个记录器的名称后跟一个点是后代记录器名称的前缀,则该记录器被称为另一个记录器的祖先。如果记录器本身和后代记录器之间没有祖先,则称记录器为子记录器的父记录器。
例如,名为 "com.foo" 的记录器是名为 "com.foo.Bar" 记录器的父级。 类似地, "java" 是 "java.util" 的父,并且是 "java.util.Vector" 的祖先。 大多数开发人员都应该熟悉这种命名方案。
根记录器位于记录器层次结构的顶部。它是例外的,因为它是每一个层次的一部分,在其成立之初。与每个记录器一样,可以按其名称检索,如下所示:
Logger rootLogger = LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME);
所有其他记录器也是通过 org.slf4j.LoggerFactory 类中静态方法 getLogger
来获取的。此方法将所需记录器的名称作为参数。下面列出了Logger接口中的一些基本方法。
package org.slf4j;
public interface Logger {
// Printing methods:
public void trace(String message);
public void debug(String message);
public void info(String message);
public void warn(String message);
public void error(String message);
}
有效等级又称等级继承
Logger
可以分配等级。有一系列的级别(TRACE
、DEBUG
、INFO
、WARN
和 ERROR
)已经定义在 ch.qos.logback.classic.Level
类里面了。注意,在 Logback 中,Level
类是 final 修饰符修饰的类,它不能被继承,也就是说他不能有子类,因为有一个扩展更好的方式,就是使用 Marker
对象,它更加的灵活,所以不需要使用 Level
类来扩展。
如果我们没有为一个 logger
对象分配日志等级,它会从最近的一个父 logger
继承。请看下面的解释:
给定记录器 L 的有效级别等于其层次结构中的第一个非空级别,从 L 本身开始,在层次结构中向上延伸到根记录器。
为了确保所有记录器最终都可以继承一个级别,根记录器总是有一个指定的级别。默认情况下,此级别为DEBUG。
下面是四个示例,其中包含各种指定的级别值以及根据级别继承规则生成的有效(继承)级别。
示例 1
记录器名字 | 分配等级 | 有效等级 |
---|---|---|
root | DEBUG | DEBUG |
X | none | DEBUG |
X.Y | none | DEBUG |
X.Y.Z | none | DEBUG |
在上面的示例1中,只有根记录器被分配了级别,其他的记录器,比如 X、X.Y、X.Y.Z,这三个记录器都会继承根记录器的级别。
示例 2
记录器名字 | 分配等级 | 有效等级 |
---|---|---|
root | ERROR | ERROR |
X | INFO | INFO |
X.Y | DEBUG | DEBUG |
X.Y.Z | WARN | WARN |
在上面的示例2中,所有记录器都有一个指定的级别值。等级继承不起作用。
示例 3
记录器名字 | 分配等级 | 有效等级 |
---|---|---|
root | DEBUG | DEBUG |
X | INFO | INFO |
X.Y | none | INFO |
X.Y.Z | ERROR | ERROR |
在上面的示例 3 中,分别为记录器 root
、X
和 X.Y.Z
分配了级别 DEBUG
、INFO
和 ERROR
。记录器 X.Y
从其父级 X
继承其级别值。
示例 4
记录器名字 | 分配等级 | 有效等级 |
---|---|---|
root | DEBUG | DEBUG |
X | INFO | INFO |
X.Y | none | INFO |
X.Y.Z | none | INFO |
在上面的示例 4 中,分别为记录器 root
和 X
分配了级别 DEBUG
和 INFO
。记录器 X.Y
和 X.Y.Z
从最近的父级 X
继承其级别值,后者具有指定的级别。
打印方法和基本选择原则
根据定义,打印方法确定日志记录请求的级别。例如如果 L
是一个记录器实例对象,那么 L.info("..")
是一个 INFO 级别的日志打印语句。也就是说,我们调用的方法就决定了我们日志输出的级别。
当我们调用记录器实例对象的方法的时候,如果这个方法的等级高于我们设定的级别那么就会输出,否则不会输出日志。如前所述,没有指定级别的记录器将从其最近的祖先继承一个级别。这条规则总结如下。
基本选择规则
如果p>=q,则向有效级别为q的记录器发出的级别为p的日志请求将被启用。
其实说白了,就是我们在请求日志记录的时候,请求的方法的级别要比我们设置的或者继承的级别更高才行,不然日志是不会打印的。下面就会介绍如何来比较日志的等级。
这条规则是 logback 的核心。级别的顺序如下:TRACE < DEBUG < INFO < WARN < ERROR
。
也就是说,ERROR
比 WARN
的级别高,依次类推,所以我们在调用方法的时候,如果设定的有效级别或继承的有效级别是 WARN
,那么我们在调用方法的时候调用 warn
或者 error
都会打印,但是其他级别是不会打印的。
以更形象的方式,下面是选择规则的工作原理。在下表中,垂直标头显示日志请求的级别,由p指定,而水平标头显示记录器的有效级别,由q指定。行(级别请求)和列(有效级别)的交集是基本选择规则产生的布尔值。
请求等级 p | 有效等级 q | 有效等级 q | 有效等级 q | 有效等级 q | 有效等级 q | 有效等级 q |
---|---|---|---|---|---|---|
TRACE | TRACE | DEBUG | INFO | WARN | ERROR | OFF |
TRACE | YES | YES | NO | NO | NO | NO |
DEBUG | YES | YES | YES | NO | NO | NO |
INFO | YES | YES | YES | YES | NO | NO |
WARN | YES | YES | YES | YES | YES | NO |
ERROR | YES | YES | YES | YES | YES | YES |
下面是一个基本选择规则的示例。
package chapters.introduction;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Level;
public class HelloWorld4 {
public static void main(String[] args) {
// 获得一个名字为 "com.foo" 的记录器实例。
// 让我们将类 Logger 的包一起指定,以便我们可以更方便的设置它的级别
ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("com.foo");
// 设置级别为 INFO。 setLevel() 方法需要一个 logback 记录器对象
logger.setLevel(Level.INFO);
Logger barlogger = LoggerFactory.getLogger("com.foo.Bar");
// 这个日志会打印,因为 WARN >= INFO
logger.warn("Low fuel level.");
// 这个打印日志的请求不会被执行,因为 DEBUG < INFO.
logger.debug("Starting search for nearest gas station.");
// 记录器实例对象 barlogger, 它的名字是 "com.foo.Bar",将会从 "com.foo" 继承日志等级。
// 因此,接下来的打印日志请求将会成功执行,因为 INFO >= INFO.
barlogger.info("Located nearest gas station.");
// 这个打印日志的请求就不会打印出日志,因为 DEBUG < INFO.
barlogger.debug("Exiting gas station search");
}
}
输出:
17:58:57.016 [main] WARN com.foo - Low fuel level.
17:58:57.020 [main] INFO com.foo.Bar - Located nearest gas station.
检索记录器
调用 LoggerFactory.getLogger
方法,如果传入其中的参数相同,那么返回的记录器对象的引用是完全相同的。
例如,在
package chapters.introduction;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class HelloWorld5 {
public static void main(String[] args) {
Logger x = LoggerFactory.getLogger("wombat");
Logger y = LoggerFactory.getLogger("wombat");
x.info(x == y ? "true" : "false");
y.info(x == y ? "true" : "false");
}
}
输出:
17:57:56.528 [main] INFO wombat - true
17:57:56.533 [main] INFO wombat - true
通过上面的例子,我们可以看出,x
和 y
指向的是相同的记录器对象。
因此,可以配置一个记录器,然后在代码中的其他地方检索相同的实例,而无需传递引用。这里跟我们现实世界里的父子关系有一点不一样,我们现实生活中是应该先有父母才有子女的,但是 Logback 是不需要关注他们的先后顺序的,也就是说,他们的父子关系与先后创建的关系是无关的。需要特别说明的是,一个 “父级” 的记录器将查找并链接到他的子记录器上,即使父记录器是在子记录器之后实例化的。
logback 环境的配置通常在应用程序初始化时完成。首选方法是读取配置文件。这一方法将很快讨论。
Logback 对记录器命名非常容易,只需要我们在每个类里面是一个记录器就可以了,在传入静态方法获取记录器对象的时候传入的是类的权限定名,也就是包括了自己的包名和类名组合在一起。这是一种定义记录器特别行之有效的方法。由于日志输出带有生成日志的记录器的名称,因此这种命名策略可以很容易地识别日志消费的来源。然而,这只是一种命名记录器的可能(尽管很常见)策略。Logback 并不会限制记录器的集合,开发人员可以非常随意的命名记录器。
但是,到目前为止,我们最好还是使用全限定类名来命名记录器比较好。
Appender (附加器)和 Layout(布局)
上面我们看到了,logback 会根据我们请求打印日志的不通级别来有选择的打印一些消息,这只是 Logback 众多能力中的一个。Logback 允许日志请求打印到多个目的地。在 Logback 中,输出目的地成为 appender。目前,有控制台的 appender,文件的 appender,远程套接字服务的 appender,MySQL、PostgreSQL、Oracle和其他数据库的 appender,JMS 和远程 UNIX Syslog 守护进程的 appender。
很多 appender(附加器) 可以附加在一个 logger(记录器)上面。
addAppender
方法将附加器添加到指定的记录器中。每次我们调用记录器的方法发送打印日志的请求的时候,这些请求都会转发到这个记录器的所有附加器中,以及层级结构中更高级的附加器。换句话说,附加器是从记录器层次结构附加继承的。例如,如果控制台的附加器添加到了根记录器中,那么所有启用的日志请求都会至少打印到控制台上。如果另外一个文件附加器被添加到一个记录器中,比如说 L,那么对于 L 和 L 的子级的记录器中发送的日志请求都将打印在一个文件和控制台上。通过将记录器的 additivity 标志设置为 false,可以覆盖此默认行为,从而使附加器不再是继承父级的附加器,并将他们叠加的。
附录可加性的规则总结如下。
附加器的叠加性
记录器 L 的日志语句输出将转到 L 记录器和它的父级记录器中的所有附加器中。这就是术语 “附加器的叠加性” 的含义。
然而,如果是记录器 L 的祖先,比如我们管它叫 P,P 这个祖先已经将叠加性这个属性设置为了 false 了,那么 L 在输出日志的时候,会输出所有 L 本身自己定义的附加器,当然这是肯定的,然后还有它的父级记录器 P 所定义的附加器,但是,P 的所有父级记录器所定义的附加器都不会进行输出。
默认情况下,记录器的叠加性标志都会设置为 true。
下面的表格展示了一个示例:
记录器名称 | 其上的附加器 | 叠加性标志 | 输出目标 | 说明 |
---|---|---|---|---|
root | A1 | 不适用 | A1 | 因为根记录器位于记录器层级结构的顶部,所以叠加性标志不适用于它。 |
x | A-x1, A-x2 | true | A1, A-x1, A-x2 | 附加器包括了自身 "x" 上的附加器和根附加器。 |
x.y | none | true | A1, A-x1, A-x2 | 其上的附加器包括了 "x" 的附加器还有根的附加器。 |
x.y.z | A-xyz1 | true | A1, A-x1, A-x2, A-xyz1 | 其上的附加器包括了自身记录器 "x.y.z" 上的附加器还有 "x" 和根记录器上的附加器。 |
security | A-sec | false | A-sec | 由于记录器的叠加性标志设置为 false ,因此没有附加器的叠加。所以它只使用自己的附加器 A-sec。 |
security.access | none | true | A-sec | 只有记录器 "security" 的附加器,因为 "security" 中的叠加性标志设置为 false ,而且它自己本身也没有附加器,所以就只能继承父记录器的附加器。 |
通常,用户不仅希望自定义输出目的地,还希望自定义输出格式。这是通过将布局与追加器关联来实现的。布局负责根据用户的意愿格式化日志记录请求,而appender负责将格式化输出发送到目的地。PatternLayout
是标准 logback 的一部分,它允许用户根据与 C 语言 printf
函数类似的转换模式指定输出格式。
例如,转换模式为 "%-4relative [%thread] %-5level %logger{32} - %msg%n" 的 PatternLayout 将输出类似于:
176 [main] DEBUG manual.architecture.HelloWorld2 - Hello world.
第一个字段是自程序启动以来经过的毫秒数。第二个字段是发出日志请求的线程。第三个字段是日志请求的级别。第四个字段是与日志请求关联的记录器的名称。'-' 后面的文本是请求的消息。
参数化日志
logback-classic 模块中的记录器实现了 SLF4J 的 Logger 接口,这些打印方法允许多个参数。这些打印方法变体主要是为了提高性能,同时尽量减少对代码可读性的影响。
比如说有一个 Logger 类的对象 logger
,也就是我们所说的记录器,可以有如下的调用形式:
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
产生构造消息参数的成本,即将整数 i
和entry[i]
转换为字符串,并连接中间字符串。这与是否记录消息无关。
避免日志损耗生产环境的性能,可以先判断了是否开启了 debug ,也就是说,我们这个 记录器是否可以使用 debug 级别进行日志的输出。看下面的例子:
if(logger.isDebugEnabled()) {
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}
如果我们需要对记录器禁用 debug 模式,那么就不会产生性能的损耗。但是如果我们开启了记录器的调试模式,那么我们就需要花费两次的时间,一次是在调用 debugEnabled
的时候,另一次是在 实际调用 debug
函数的时候。在实际的生产环境或者测试环境中,经过测试,前期判断是否启用 debug 模式的判断其实损耗不了多少性能,它花费的性能还不到实际日志调用的 1%,所以调试代码用到的日志最好还是先判断一下比较好。
更好的选择
上面的日志输出中,我们有另一种比较好的输出日志的方式。假设 entry
是一个对象,您可以编写:
Object entry = new SomeObject();
logger.debug("The entry is {}.", entry);
在输出日志之前,我们需要根据目前调用日志的级别,还有记录器可以输出的级别的设置来判定目前的日志是否需要输出,如果需要输出该条日志,记录器才会格式化消息并且用 entry
对象来替换符号 '{}'。也就是说,如果判断当前要输出的级别比我们配置的输出级别低的时候,这条语句中的消息是不会去构造的,也就是不会产生任何的性能上的开销。
下面的两行代码将会产生完全相同的输出。但是,在禁用日志语句输出的情况下,第二种的输出方式比第一种至少要好30倍。
logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);
在输出日志的时候,也可以输出两个的变量,具体可以查看 debug 的 API,我们可以使用如下的方式写代码:
logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);
如果需要传递三个或更多的参数的时候,还可以使用 Object[]
变量。例如,您可以编写:
Object[] paramArray = {newVal, below, above};
logger.debug("Value {} was inserted between {} and {}.", paramArray);
底层原理
在介绍了基本的logback组件之后,现在可以描述当用户调用日志程序的打印方法时,logback框架所采取的步骤。现在让我们分析用户调用名为 com.wombat 的日志记录器的 info()
方法时,logback所采取的步骤。
1. 获得过滤器链决策
假设我们现有已经使用 LoggerFactory
的工厂方法生成了记录器的对象,并且使用这个记录器请求了一条日志,那么它就会调用 TurboFilter
链。如下就是 TurboFilter
的代码:
/**
* Logback: the reliable, generic, fast and flexible logging framework.
* Copyright (C) 1999-2015, QOS.ch. All rights reserved.
*
* This program and the accompanying materials are dual-licensed under
* either the terms of the Eclipse Public License v1.0 as published by
* the Eclipse Foundation
*
* or (per the licensee's choosing)
*
* under the terms of the GNU Lesser General Public License version 2.1
* as published by the Free Software Foundation.
*/
package ch.qos.logback.classic.turbo;
import org.slf4j.Marker;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.core.spi.ContextAwareBase;
import ch.qos.logback.core.spi.FilterReply;
import ch.qos.logback.core.spi.LifeCycle;
/**
* TurboFilter is a specialized filter with a decide method that takes a bunch
* of parameters instead of a single event object. The latter is cleaner but
* the first is much more performant.
* <p>
* For more information about turbo filters, please refer to the online manual at
* http://logback.qos.ch/manual/filters.html#TurboFilter
*
* @author Ceki Gulcu
*/
public abstract class TurboFilter extends ContextAwareBase implements LifeCycle {
private String name;
boolean start = false;
/**
* Make a decision based on the multiple parameters passed as arguments.
* The returned value should be one of <code>{@link FilterReply#DENY}</code>,
* <code>{@link FilterReply#NEUTRAL}</code>, or <code>{@link FilterReply#ACCEPT}</code>.
* @param marker
* @param logger
* @param level
* @param format
* @param params
* @param t
* @return
*/
public abstract FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t);
public void start() {
this.start = true;
}
public boolean isStarted() {
return this.start;
}
public void stop() {
this.start = false;
}
public String getName() {
return name;
}
public void setName(String name) {
this.name = name;
}
}
TurboFilter
可以设置上下文范围的阈值,或者根据与每个日志记录请求相关联的信息(如 Marker
、Level
、Logger
、消息或 Throwable
)过滤掉某些事件。如果过滤链的回复是 FilterReply.DENY
,则删除日志记录请求。如果是 FilterReply.NEUTRAL
的话,那么就进行下一步,即第2步。如果答复是 FilterReply.ACCEPT
的话,我们跳过下一步,直接跳到第3步。
2. 应用 基本选择规则
在这步中,logback 将当前记录器的有效等级与请求的等级之间进行对比。如果说根据这次比较,日志请求的等级比我们设定的等级要低的话,那么就会禁用该日志请求,并且 logback 马上会放弃这次请求,不进行任何处理。如果通过了比较,也就是说我们请求的日志等级大于或者等级我们日志记录器设定的级别的话,就会进入下一步。
3. 创建 LoggingEvent
对象
如果这次日志的请求通过上面两步的过滤,还能走到这里的话,logback 就会创建 ch.qos.logback.classic.LoggingEvent
对象。该对象包含请求的所有相关参数,例如请求的记录器、请求级别、消息本身、可能随请求一起传递的异常、当前时间,当前线程、有关发出日志记录请求的类的各种数据以及 MDC
。请注意,这些字段中的一些是延迟初始化的,这只是在实际需要时才初始化。 MDC
用于用其他上下文信息修饰日志记录请求。MDC将在[下一章]中讨论。
4. 调用附加器
创建 LoggingEvent
对象后,logback 会调用 doAppend()
方法来将所有适用的附加器(appender),这些附加器包括从日志上下文中加载的父级记录器中继承来的附加器。
logback 中的所有附加器(appender)都扩展了抽象类 AppenderBase
,这个类实现了 doAppend
方法,这个 doAppend
方法它是用 synchronized
关键字修饰的,所以执行这个 doAppend
方法是线程安全的。代码如下所示:
abstract public class AppenderBase<E> extends ContextAwareBase implements Appender<E> {
public synchronized void doAppend(E eventObject) {
}
}
上面的代码只是简单的部分代码,省略了很多冗余的部分。
如果我们自己定义了一些过滤器,并附加到这个附加器(appender)上的话,抽象类 AppenderBase
中的 doAppend
方法也会调用这些自定义的过滤器,用于过滤附加器(appender)。代码如下所示:
public synchronized void doAppend(E eventObject) {
if (getFilterChainDecision(eventObject) == FilterReply.DENY) {
return;
}
}
上面的代码同样只是展示了部分代码。
自定义的过滤器可以动态地加到任何的附加器(appender)上。详细说明我们可以在 separate chapter 中查看。
5. 格式化输出
logback 调用附加器(appender)来格式化日志的请求。但是有一些(并不是所有的)附加器会将格式化日志的任务委托给布局(layout)来执行。布局(layout)格式化 LoggingEvent
的实例对象并且将结果作为字符串返回。请注意,某些附加器(appender),比如 SocketAppender
,它并不会将日志事件转换为字符串,而是将其序列化。因此,它们没有也不需要布局(layout)。
6. 发送 LoggingEvent
日志事件完全格式化后,每个appender都会将其发送到目的地。
下面是一个 UML 的时序图,它展示了 logback是如何工作的。点击可以放大查看。
性能
反对伐木的一个经常被引用的论点是它的计算成本。这是一个合理的问题,因为即使是中等规模的应用程序也可以生成数千个日志请求。我们的大部分开发工作都花在测量和调整logback的性能上。除了这些努力之外,用户还应该意识到以下性能问题。
1. 完全关闭日志记录时的日志记录性能
您可以通过将根记录器的级别设置为 Level.OFF
,可能的最高级别。当日志记录完全关闭时,日志请求的开销包括方法调用和整数比较。在3.2Ghz的奔腾D机器上,这一成本通常在20纳秒左右。
然而,任何方法调用都涉及参数构造的“隐藏”成本。例如,对于某些记录器x写入,
x.debug("Entry number: " + i + "is " + entry[i]);
产生构造消息参数的成本,即将整数“i”和“entry[i]”转换为字符串,并连接中间字符串,而不管消息是否将被记录。
参数构造的成本可能相当高,并且取决于所涉及参数的大小。为了避免参数构造的成本,您可以利用SLF4J的参数化日志:
x.debug("Entry number: {} is {}", i, entry[i]);
这种变体不会产生参数构造的成本。与以前对 debug()
方法的调用相比,它将快很多。只有将日志记录请求发送到附加的附加程序时,才会格式化消息。此外,格式化消息的组件得到了高度优化。
尽管有上述规定,将日志语句置于紧密循环中(即非常频繁地调用代码)是一种两败俱伤的建议,可能会导致性能下降。即使关闭了日志记录,紧密循环中的日志记录也会降低应用程序的速度,如果打开日志记录,则会生成大量(因此是无用的)输出。
2. 在日志记录打开时决定是否记录的性能。
在logback中,不需要遍历logger层次结构。记录器在创建时知道它的有效级别(即,一旦考虑到级别继承,它的级别)。如果父记录器的级别发生更改,则会联系所有子记录器以注意更改。因此,在基于有效级别接受或拒绝请求之前,记录器可以做出准即时决策,而无需咨询其祖先。
3. 实际记录(格式化并写入输出设备)
这是格式化日志输出并将其发送到目标的成本。在这里,我们再一次认真地努力使布局(格式化程序)尽可能快地执行。追加者也是如此。当记录到本地计算机上的文件时,实际记录的典型成本约为9到12微秒。当登录到远程服务器上的数据库时,时间会长达几毫秒。
尽管功能丰富,logback最重要的设计目标之一是执行速度,这是仅次于可靠性的要求。一些logback组件已被重写多次以提高性能。