Java中的日志系统及在SpringBoot中的使用
为什么需要日志框架
在Java的实际开发中,需要将程序的一些运行信息打印或写入日志文件。System.out是在当前线程执行的,即将日志写入文件后才会执行下面的程序,会极大的影响运行效率。因此在实际开发中都会使用SLF4J(Simple Logging Façade For Java)+ 其实现类(log4j、logback等)实现日志的记录和输出。
SLF4J概念
实际开发的系统中可能需要使用不同的日志框架,例如自己的系统中使用了logback实现日志输出,而系统的依赖A.jar使用了log4j框架。为了同时支持和维护不同日志框架,提出了SLF4J(Simple Logging Façade For Java)。SLF4J是门面模式的典型应用,可以简单理解成日志系统的适配层,决定具体使用哪一种日志框架,这样调用端只需要打印日志而不需要关心如何打印日志。
门面(Facade)模式
门面模式,其核心为外部与一个子系统的通信必须通过一个统一的外观对象进行,使得子系统更易于使用。可以通过下图进行理解:
在这个对象图中,出现了两个角色:
门面(Facade)角色 :知道所有子角色的功能和责任;将客户端发来的请求委派到子系统中,没有实际业务逻辑;不参与子系统内业务逻辑的实现。
子系统(SubSystem)角色 :可以同时有一个或者多个子系统。每个子系统都不是一个单独的类,而是一个类的集合(如上面的子系统就是由ModuleA、ModuleB、ModuleC三个类组合而成)。每个子系统都可以被客户端直接调用,或者被门面角色调用。子系统并不知道门面的存在,对于子系统而言,门面仅仅是另外一个客户端而已。
SLF4J就相当于所有日志框架的门面,它只做两件事情:
- 提供日志接口
- 提供获取具体日志对象的方法
SLF4J实现原理
在代码中,使用SLF4J非常简单,只需要使用下面的一行代码就能通过LoggerFactory去拿SLF4J提供的一个Logger接口的具体实现。
Logger logger = LoggerFactory.getLogger(this.getClass());
通过观察LoggerFactory中getLogger的源码
/**
* Return a logger named corresponding to the class passed as parameter,
* using the statically bound {@link ILoggerFactory} instance.
* */
public static Logger getLogger(Class<?> clazz) {
Logger logger = getLogger(clazz.getName());
if (DETECT_LOGGER_NAME_MISMATCH) {
Class<?> autoComputedCallingClass = Util.getCallingClass();
if (autoComputedCallingClass != null && nonMatchingClasses(clazz, autoComputedCallingClass)) {
Util.report(String.format("Detected logger name mismatch. Given name: \"%s\"; computed name: \"%s\".", logger.getName(),
autoComputedCallingClass.getName()));
Util.report("See " + LOGGER_NAME_MISMATCH_URL + " for an explanation");
}
}
return logger;
}
这里关键是第二行的getLogger方法,后面的逻辑是如果使用类的名字和传入类的名字不一致时会输出logger name mismatch warning ,但也要在系统变量中将DETECT_LOGGER_NAME_MISMATCH设置为true才会生效。
public static Logger getLogger(String name) {
ILoggerFactory iLoggerFactory = getILoggerFactory();
return iLoggerFactory.getLogger(name);
}
ILoggerFactory是个接口,里面只有getLogger一个方法,关键在于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:
return SUBST_FACTORY;
}
throw new IllegalStateException("Unreachable code");
}
private final static void performInitialization() {
bind();
if (INITIALIZATION_STATE == SUCCESSFUL_INITIALIZATION) {
versionSanityCheck();
}
}
可以看出,一开始当 INITIALIZATION_STATE 是UNINITIALIZED 时(即第一次调用该方法时),通过 performInitialization() 方法中的 bind() 方法去发现和绑定日志框架。
private final static void bind() {
try {
Set<URL> staticLoggerBinderPathSet = null;
if (!isAndroid()) {
//找到所有StaticLoggerBinder.class存在的路径
staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
//如果有多处存在StaticLoggerBinder.class,下面的方法会发出警告
reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
}
// the next line does the binding
StaticLoggerBinder.getSingleton();
INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
reportActualBinding(staticLoggerBinderPathSet);
fixSubstituteLoggers();
replayEvents();
// release all resources in SUBST_FACTORY
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);
}
}
这里通过第5行的 findPossibleStaticLoggerBinderPathSet() 方法找到所有logger框架可能的绑定路径,并在第9行的 StaticLoggerBinder.getSingleton() 方法中实现绑定。
private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";
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;
}
该方法最终返回所有 StaticLoggerBinder.class 的存在路径,即所有SLF4J的实现的jar包路径下,org/slf4j/impl/StaticLoggerBinder.class 是一定存在的。
最终,SLF4J将具体日志框架的 StaticLoggerBinder.class 绑定在了StaticLoggerBinder 对象中,通过 StaticLoggerBinder.getSingleton().getLoggerFactory().getLogger(name) 可以得到具体的Logger对象。
SpringBoot中日志的使用
日志框架的关系
slf4j-simple、logback都是SLF4J的具体实现,log4j并不直接实现SLF4J,但是有专门的一层桥接slf4j-log4j12来实现slf4j。其中,slf4j-simple不常用,因此主要介绍logback和log4j。logback是log4j的改良版本,比log4j拥有更多的特性,同时也带来很大性能提升。因此 SpringBoot 提供了一套日志系统,logback是最优先的选择。关于这一点,我们可以从点击pom.xml文件里的 spring-boot-starter-parent 中的spring-boot-dependencies
pom.xml:
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.2.2.RELEASE</version>
</parent>
spring-boot-starter-parent-2.2.2.RELEASE.pom.xml:
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-dependencies</artifactId>
<version>2.2.2.RELEASE</version>
<relativePath>../../spring-boot-dependencies</relativePath>
</parent>
可以看到以下依赖:
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-access</artifactId>
<version>${logback.version}</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>${logback.version}</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>${logback.version}</version>
</dependency>
其中,logback被分为3个组件,logback-core, logback-classic 和 logback-access。
其中logback-core提供了logback的核心功能,是另外两个组件的基础。
logback-classic则实现了SLF4J的API,所以当想配合SLF4J使用时,需要将logback-classic加入classpath。
当然,也可以选择不使用 SpringBoot 自带的日志系统而使用log4j,但此时需要先在依赖中排除 SpringBoot 自带的日志系统,再引入log4j的依赖,如下:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>
<!-- log4j. -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j</artifactId>
</dependency>
logback的使用
默认配置
SpringBoot 默认帮我们配置好了日志;日志有五种级别,由低到高是trace<debug<info<warn<error,日志就只会在这个级别及更高级别生效,SpringBoot 默认指定是info级别,
private Logger logger = LoggerFactory.getLogger(this.getClass());
@Test
public void printLog() {
logger.trace("This is Trace Logger.");
logger.debug("This is Debug Logger.");
logger.info("This is Info Logger.");
logger.warn("This is Warn Logger.");
logger.error("This is Error Logger.");
}
运行上面的测试类,可以得到
2020-05-11 14:22:11.068 -- [main] -- INFO -- com.temp.LogTest -- This is Info Logger.
2020-05-11 14:22:11.069 -- [main] -- WARN -- com.temp.LogTest -- This is Warn Logger.
2020-05-11 14:22:11.070 -- [main] -- ERROR -- com.temp.LogTest -- This is Error Logger.
这印证了SpringBoot的默认日志配置级别为Info的事实。
自定义配置
可以在resource/applications.properties文件中加入以下属性修改日志的配置。
修改默认级别为error。
logging.level.root = error
如果仅想指定某个包内的日志级别可以将root改为包名。
logging.level.com.test.web = error
这样该包下的所有日志输出级别将改为error,其他包不受影响。(注:如果同时指定了上面两者,后者将覆盖前者)
指定输出日志文件
logging.file.name=./springboot.log
该属性指定在resource/下生成一个springboot.log文件存放日志。
logging.file.path=/log
该属性指定日志的目录在resource/log下,会自动生成一个springboot.log文件存放日志。
(注:两者同时指定,前者生效。当检测到日志的生成时间和日志文件里日志的时间相差一天时,会自动将原日志名称改为springboot.log.2020-05-10.0(前一天时间).gz,重新生成springboot.log存放当天的日志)
修改输出格式
logging.pattern.console = %d{yyyy-MM-dd HH:mm:ss.SSS} -- [%thread] -- %-5level -- %logger{50} -- %msg%n
logging.pattern.file = %d{yyyy-MM-dd HH:mm:ss.SSS} -- [%thread] -- %-5level -- %logger{50} -- %msg%n
前者指定在控制台输出的格式,后者指定在文件中输出的格式。其中:
%d:表示日期时间;
%thread:表示线程名;
%-5level:级别从左显示固定5个字符宽度;
%logger{50}:表示logger名字,意思是最长50个字符,否则按照句点分割;
%msg:日志消息;
%n是换行符;
可以通过上述符号自定义想要的日志输出格式。
指定配置文件
logging.config=classpath:log/logback-spring.xml
该属性指定了日志的配置文件从resouce/log/logback-spring.xml进行读取。(注:如果直接在/resouce下建立logback.xml,则不需要显示指定路径,SpringBoot会自动在该路径下识别该文件。如果配置文件中的属性和applications.properties文件冲突,以后者为准。)
多环境日志配置
在/resource下直接建立lockback.xml可以不需要显示指定配置文件路径,但是官方依旧推荐优先使用 *-spring.* 的形式命名日志配置文件,因为使用该命名可以获得spring扩展的profile支持,即springProfile标签,实现根据不同环境(prod:生产环境,test:测试环境,dev:开发环境)来定义不同的日志输出。配置文件内容如下:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/base.xml" />
<logger name="org.springframework.web" level="INFO"/>
<logger name="org.springboot.sample" level="TRACE" />
<!-- 测试环境+开发环境. 多个使用逗号隔开. -->
<springProfile name="test,dev">
<logger name="org.springframework.web" level="INFO"/>
<logger name="org.springboot.sample" level="INFO" />
<logger name="com.kfit" level="info" />
</springProfile>
<!-- 生产环境. -->
<springProfile name="prod">
<logger name="org.springframework.web" level="ERROR"/>
<logger name="org.springboot.sample" level="ERROR" />
<logger name="com.kfit" level="ERROR" />
</springProfile>
</configuration>
参考文献
[1] https://www.iteye.com/blog/412887952-qq-com-2307244
[2] https://www.cnblogs.com/zhangjianbing/p/8992897.html
[3] https://www.cnblogs.com/xrq730/p/8619156.html
[4] https://www.cnblogs.com/zouwangblog/p/11198915.html