知识点
- logback在会先加载classpath下的logback-test.xml,如果没有找到再加载logback.xml。
- Logback中三大核心概念:Logger、Appender和Layout。
- Logger采用层级架构,采用类似java的package的命名方式,名为
a.b
的Logger是a.b.c
的parent,而后者则为前者的child,如果两个logger之间间隔了几层,比如a.b
和a.b.c.d
,那么a.b
为a.b.c.d
的ancestor,反之a.b.c.d
为a.b
的descendant。 - Logger本身可以设置Level,Level从高到低有:ERROR,WARN,INFO,DEBUG,TRACE。除了设置Level之外,在实际打日志时通过
logger.info()
其实指定的是请求Level,只有当请求Level高于Logger的设置Level时,该Logger才生效。这个不难理解,因为Level级别越高,表示越应该记录下该Logger。比如,当设置Level为INFO时,表示输入一些正常的日志事件,但是如果系统中出现了错误,即通过logger.error()
输入日志,很明显这个错误是我们更应该关心的,因此该日志时需要记录下来的。 - 多数时候,我们没有必要为每个logger设置level,此时并不代表logger没有level,而是继承了离其最近的ancestor,此处Logger的层级架构便起作用了。在层级的最上层,有个固定的名为ROOT的logger,表示任何logger如果没有设置的ancestor,那么其Level便继承自ROOT。Logback的ROOT的默认Level为DEBUG。
- Logger在输出日志时,是通过Appender来完成的,有的Appender将日志输出到命令行,有的输出到文件,有的则输出到数据库或者消息队列。一个Logger可以有多个Appender,也即该Logger的日志会输出到多个地方。
- 对于Appender,Logback有个重要的性质:如果某个Logger得到了启用(即请求Level高于其有效设置Level),那么除了该Logger自身所拥有的Appender会输出日志之外,该Logger的所有ancestor的Appender也会输出日志。这也是为什么在通常情况下,我们只需要为ROOT设置appender的原因。Logabck的这个性质其实依赖于Logback的additivity属性,事实上是该属性确定了是否将日志请求向上级Logger的appender发送。在默认情况下,additivity=true,则表示日志会输送到所有上级Logger的appender。当然,我们可以设置为false,使某个Logger的日志只是输出到某些特定的地方。比如,我们希望只将性能测试的日志输入到某个文件中,而将系统中的所有其他日志输出到命令行中。
- 需要注意的是,additivity与level无关,就是说即便child logger的level比parent logger的低,child logger的additivity=true,那么只要child logger被启用,那么其日志依然会上传到parent logger的appender中。
案例项目
└── src
└── main
├── java
│ └── davenkin
│ └── parent
│ ├── Parent.java
│ ├── child1
│ │ └── Child1.java
│ └── child2
│ └── Child2.java
└── resources
└── logback.xml
其中Parent中main函数分别输出Parent,Child1和Child2的日志。
- logback.xml:
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<appender name="ROOT_FILE" class="ch.qos.logback.core.FileAppender">
<file>root.log</file>
<append>true</append>
<encoder>
<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
</encoder>
</appender>
<root level="info">
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROOT_FILE"/>
</root>
</configuration>
- Parent:
package davenkin.parent;
import davenkin.parent.child1.Child1;
import davenkin.parent.child2.Child2;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Parent {
private static final Logger logger = LoggerFactory.getLogger(Parent.class);
public static void main(String[] args) {
logger.info("info from parent");
logger.debug("debug from parent");
new Child1().hello();
new Child2().hello();
}
}
- Child1:
package davenkin.parent.child1;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Child1 {
private static final Logger logger = LoggerFactory.getLogger(Child1.class);
public void hello() {
logger.info("info from child1");
logger.debug("debug from child1");
}
}
- Child2:
package davenkin.parent.child2;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Child2 {
private static final Logger logger = LoggerFactory.getLogger(Child2.class);
public void hello() {
logger.info("info from child2");
logger.debug("debug from child2");
}
}
常用配置
以上例子是一个常见的日志配置,其中:没有为任何Logger显式配置Level与additivity属性,而只是配置了一个root logger,即表示所有日志最终都会打到root logger所对应的appender中,日志同时打到了命令行和文件中。root logger的Level设置成了INFO,表示debug的日志请求不会得到输出。这样的配置常见于生产环境,因为很多第三方类库都会输出大量的debug日志,这样会使得我们正常的INFO级别的业务记录日志淹没在debug日志中。
此时的命令行输出日志如下:
09:03:01.304 INFO davenkin.parent.Parent - info from parent
09:03:01.306 INFO davenkin.parent.child1.Child1 - info from child1
09:03:01.306 INFO davenkin.parent.child2.Child2 - info from child2
为某个package下的日志设置单独的Level
有时为了调试方便,我们可能需要将某个package下的debug或者trace日志输出,比如在用Spring的WebserviceTemplate时,我们希望打印出请求和返回的XML数据,那么此时便可以显式地为对应logger设置Level:
<logger name="org.springframework.ws.client.MessageTracing">
<level value="TRACE"/>
</logger>
<logger name="org.springframework.ws.server.MessageTracing">
<level value="TRACE"/>
</logger>
对应到上面的案例项目,如果我们希望child1包下能够打印出debug级别的日志,那么可以修改logback.xml文件,在其中显式配置logger:
<logger name="davenkin.parent.child1">
<level value="DEBUG"/>
</logger>
此时输出日志中便包含了child1下的DEBUG日志,但是不包含其他package下的DEBUG日志:
09:09:10.935 INFO davenkin.parent.Parent - info from parent
09:09:10.938 INFO davenkin.parent.child1.Child1 - info from child1
09:09:10.938 DEBUG davenkin.parent.child1.Child1 - debug from child1
09:09:10.938 INFO davenkin.parent.child2.Child2 - info from child2
将不同logger的日志打入到不同的文件中
有时我们希望将某些logger的日志输出到单独的文件中,比如在做性能测试时,需要将所有性能测试的日志输出到perfomance.log中,这时需要为性能测试专门创建一个logger,比如名为perfomance-logger,我们需要做3件事情:
- 在代码中输出日志时,不能使用类名来命名logger,而是直接使用performance-logger:
Logger performanceLogger = LoggerFactory.getLogger("performance-logger");
- 专门配置一个属于性能日志的appender:
<appender name="PERFORMANCE_LOG" class="ch.qos.logback.core.FileAppender">
<file>performance.log</file>
<encoder>
<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
</encoder>
</appender>
- 然后在配置logger时,设置perfomance-logger的additivity=false,这样便可防止性能日志输出到其他地方。
<logger name="performance-logger" level="DEBUG" additivity="false">
<appender-ref ref="PERFORMANCE_LOG"/>
</logger>
对于,上面的例子项目,加入Child3:
package davenkin.parent.child3;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Child3 {
private static final Logger logger = LoggerFactory.getLogger("performance-logger");
public void hello() {
logger.debug("debug from performance");
}
}
在logback.xml中加入以下配置:
<appender name="PERFORMANCE_LOG" class="ch.qos.logback.core.FileAppender">
<file>performance.log</file>
<append>true</append>
<encoder>
<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
</encoder>
</appender>
<logger name="performance-logger" level="DEBUG" additivity="false">
<appender-ref ref="PERFORMANCE_LOG"/>
</logger>
再修改Parent让其输出Child3的日志:
public static void main(String[] args) {
logger.info("info from parent");
logger.debug("debug from parent");
new Child1().hello();
new Child2().hello();
new Child3().hello();
}
得到命令行输出:
09:38:58.301 INFO davenkin.parent.Parent - info from parent
09:38:58.304 INFO davenkin.parent.child1.Child1 - info from child1
09:38:58.304 DEBUG davenkin.parent.child1.Child1 - debug from child1
09:38:58.304 INFO davenkin.parent.child2.Child2 - info from child2
可以看到,命令行中不包含performance日志,而在performance.log中得到了performance日志:
198 [main] DEBUG performance-logger - debug from performance
将不同Level的日志打到不同文件中
可以通过配置Filter的方式将不同Level的日志打到不同的文件中,Filter是配置在Appender中的,具体参考这里和这里。
最佳实践
- log不应该包含敏感信息,比如用户密码等。
- log中应该包含对应资源ID,比如在操作某个User时,应该记录该User的ID。
- log中应该包含足够多的上下文信息。
- 创建log时,采用static和final关键字:
private static final Logger LOG = LoggerFactory.getLogger(Foo.class);
- 对于异常日志应该统一处理,比如在Spring的ExceptionHandler中打印异常日志,而此时异常的message应该包含足够的上下文信息。
- 发生异常时,不要打印日志然后再次抛出异常,这样导致日志输出2次:
catch (NoSuchMethodException e) { LOG.error("Blah", e); throw e; }
- log中应该包含请求的ID,可以将请求ID放在MDC中。
- log中应该包含操作者的ID,在Spring Security完成认证后,可以将操作者ID放在MDC中。
- 在WriteApplicationService中,应该记录下业务日志,也即每次对系统一个业务操作,都应该有记录,而在ApplicationService中时最合适的,因此它对应了一次业务用例。
- 在ReadApplicationService中,通常没有必要记录日志,除非此时系统产生了异常。
网友评论