Log

解析常见 Log 框架的用法

常见 Log 框架

  • JDK Logger: 鸡肋,很少在线上系统中被使用
  • Apache Commons Logging + Apache Log4j: 前者提供通用日志接口,后者提供实现
  • Slf4j + Logback: 前者提供统一接口
  • Apache Log4j2

Apache Commons Logging + Apache Log4j

1
2
3
4
5
6
<!-- 通用日志接口 -->
<dependency>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
<version>1.2</version>
</dependency>

使用方法:

1
Log log = LogFactory.getLog(CommonsLoggingDemo.class);

(1) slf4j

添加 slf4j 依赖:

1
2
3
4
5
6
<!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-api -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.25</version>
</dependency>

需要结合任意一个实现,比如 Log4j:

1
2
3
4
5
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.7.25</version>
</dependency>

注: 添加这个依赖之后,就不需要添加其它的 log4j Maven 依赖了

如何使用:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Wombat {

final Logger logger = LoggerFactory.getLogger(Wombat.class);
Integer t;
Integer oldT;

public void setTemperature(Integer temperature) {

oldT = t;
t = temperature;

logger.debug("Temperature set to {}. Old temperature was {}.", t, oldT);

if(temperature.intValue() > 50) {
logger.info("Temperature has risen above 50 degrees.");
}
}

}

1
Failed to load class org.slf4j.impl.StaticLoggerBinder

This warning message is reported when the org.slf4j.impl.StaticLoggerBinder class could not be loaded into memory. This happens when no appropriate SLF4J binding could be found on the class path. Placing one (and only one) of slf4j-nop.jar, slf4j-simple.jar, slf4j-log4j12.jar, slf4j-jdk14.jar or logback-classic.jar on the class path should solve the problem.

logback

1
2
3
4
5
6
7
8
9
10
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>1.2.3</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>${logback.version}</version>
</dependency>

logback 是由 log4j 创始人设计的又一个开源日志组件。程序运行时,logback 会查找默认的配置文件 logback.xml 或者 logback-test.xml 文件,如果没有找到它就会使用默认的配置,将日志打印到 console 中。下面是一个简单配置文件:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
<configuration>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- encoders are assigned the type
ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>

<root level="debug">
<appender-ref ref="STDOUT" />
</root>
</configuration>

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
<appender name="DefaultAppender"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${user.home}/logs/rocketmqlogs/tools_default.log</file>
<append>true</append>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<fileNamePattern>${user.home}/logs/rocketmqlogs/otherdays/tools_default.%i.log
</fileNamePattern>
<minIndex>1</minIndex>
<maxIndex>5</maxIndex>
</rollingPolicy>
<triggeringPolicy
class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<maxFileSize>100MB</maxFileSize>
</triggeringPolicy>
<encoder>
<pattern>%d{yyy-MM-dd HH:mm:ss,GMT+8} %p %t - %m%n</pattern>
<charset class="java.nio.charset.Charset">UTF-8</charset>
</encoder>
</appender>
  • FixedWindowRollingPolicy: 当保存了 5 个文档之后,将覆盖最早的日志

(2) log4j

log4j 是线程安全的

添加依赖:

1
2
3
4
5
6
<!-- https://mvnrepository.com/artifact/log4j/log4j -->
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>1.2.17</version>
</dependency>

2.1 打印到 Console:

log4j.properties 文件的内容:

使用:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
public class Foo {

final Logger classLogger = Logger.getLogger(Foo.class);
final Logger infoLogger = Logger.getLogger("INFO");

public Foo() {
classLogger.info("new Foo");
infoLogger.info("new Foo");
}

public static void main(String[] args) {
new Foo();
}

}

2.2 同时打印到 Console 和文件 log.out 中:

1
2
3
4
5
6
7
8
9
log4j.rootLogger = DEBUG, console, file

log4j.appender.console = org.apache.log4j.ConsoleAppender
log4j.appender.console.layout=org.apache.log4j.PatternLayout

log4j.appender.file = org.apache.log4j.RollingFileAppender
log4j.appender.file.file = log.out
log4j.appender.file.layout = org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

Intellij Idea 中直接运行后 log.out 文件存放的位置:

打成 Jar 包以后运行后 log.out 文件存放的位置:

2.3 单独指定某个类的日志输出到指定文件中

你需要自定义 Logger:

1
2
3
4
5
6
log4j.logger.com.zk.Foo = DEBUG, fooFile

log4j.appender.fooFile.file = fooFile.out
log4j.appender.fooFile = org.apache.log4j.RollingFileAppender
log4j.appender.fooFile.layout = org.apache.log4j.PatternLayout
log4j.appender.fooFile.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

使用:

1
2
3
4
5
6
7
8
9
public class Foo {

final Logger classLogger = Logger.getLogger(Foo.class);

public Foo() {
classLogger.info("new Foo");
}

}

2.4 避免自定义 Logger 的内容同时输出到 rootLogger

默认情况下 com.zk.Foo 这个 Logger 输出的内容会在 rootLoggercom.zk.Foo 都打印一份:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
log4j.rootLogger = DEBUG, console, file

log4j.appender.console = org.apache.log4j.ConsoleAppender
log4j.appender.console.layout=org.apache.log4j.PatternLayout

log4j.appender.file = org.apache.log4j.RollingFileAppender
log4j.appender.file.file = log.out
log4j.appender.file.layout = org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

log4j.logger.com.zk.Foo = DEBUG, fooFile
log4j.additivity.com.zk.Foo = false

log4j.appender.fooFile.file = fooFile.out
log4j.appender.fooFile = org.apache.log4j.RollingFileAppender
log4j.appender.fooFile.layout = org.apache.log4j.PatternLayout
log4j.appender.fooFile.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

添加这行代码可以只使用 com.zk.Foo 这个 Logger 来打印:

1
log4j.additivity.com.zk.Foo = false

2.5 ConversionPattern 可用的描述符号

  • c: The Logger used to invoke this logging request.
  • C: The fully qualified name of the Logger invoking this logging request.
  • d: The date of the logging request.
  • F: 调用打印日志的代码所在的文件
  • l: The location information.
  • L: 行号
  • m: 消息
  • M: 方法
  • n: 行分隔符
  • p: Level
  • r: 相对毫秒
  • t: 线程
  • x: NDC 信息
  • X: MDC 信息
  • %: 字面量

RollingFileAppender

Log4j 通过代码配置一个 Console 输出 Appender:

把这段代码放到 main 函数所在类:

1
2
3
4
5
6
static {
ConsoleAppender consoleAppender = new ConsoleAppender();
consoleAppender.setLayout(new PatternLayout(PatternLayout.DEFAULT_CONVERSION_PATTERN));
consoleAppender.activateOptions();
org.apache.log4j.BasicConfigurator.configure(consoleAppender);
}

Log4j 的问题

默认 Appenders 采用同步锁实现,太多日志会使服务的性能下降。


改进: 把同步操作改为异步操作 (使用一个缓冲队列),然后用单独的消费者线程去消费缓冲队列,异步地将缓冲队列的日志内容打印到日志文件中。

不要使用 ConcurrentLinkedQueue 作为缓冲队列,ConcurrentLinkedQueuesize() 方法的实现并不是常量时间复杂度的,而是 O(n) 的,即每次调用 size() 方法都需要实时计算队列的大小,导致 CPU 利用率加大。 建议采用 ArrayBlockingQueue 来实现。

在消费缓冲队列时,可以:

  • 一条一条地顺序消费,就是使用一个无限循环的队列,只要缓冲队列不为空,就从队列中取日志后写入日志文件中。
  • 批量消费模式会定时地取批量日志事件然后写入日志文件中。

Log4j 是通过构建异常从异常堆栈中提取方法名、文件名和行号的,不推荐在日志中使用 %L, %M, %F, %l 占位符来显示相关信息等,但可以使用 %c 来打印类名。

Log4j 如何查找 {}

(3) log4j 2.X 版本

1
2
3
4
5
6
7
8
9
10
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.8.2</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.8.2</version>
</dependency>

log4j2.xml 文件的内容如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<Root level="trace">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>

我的编程习惯 – 日志建议

对日志的最少有以下2点要求:

  • 能找到那个机器

这样,从返回头里面就能知道是哪台机器处理的请求,返回的响应:

  • 能找到用户做了什么

读取日志文件目录

读取第一个匹配的日志文件:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
try {
org.apache.log4j.Logger logger = LogManager.getRootLogger();
if (logger != null) {
Enumeration<Appender> appenders = logger.getAllAppenders();
if (appenders != null) {
while (appenders.hasMoreElements()) {
Appender appender = appenders.nextElement();
if (appender instanceof FileAppender) {
FileAppender fileAppender = (FileAppender) appender;
String filename = fileAppender.getFile();
file = new File(filename);
break;
}
}
}
}
} catch (Throwable t) {
}

log4j.properties

有如下日志文件:

1
2
3
4
5
6
7
8
9
10
log4j.rootLogger = DEBUG,I,E,S,W,stdout

#console
log4j.appender.S = org.apache.log4j.ConsoleAppender
log4j.appender.S.Threshold = INFO
log4j.appender.S.Target = System.out
log4j.appender.S.layout = org.apache.log4j.PatternLayout
log4j.appender.S.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %F:%L %-16t - %m%n

#其他的将会省略…

这个 log4j.properties 最终会被转为:


上述介绍的是 rootLogger,当你自定义 logger 的时候:

1
2
3
4
5
6
7
8
9
log4j.logger.pageTask = INFO, pageTaskFile, S
log4j.additivity.pageTask = false

log4j.appender.pageTaskFile = org.apache.log4j.DailyRollingFileAppender
log4j.appender.pageTaskFile.file = ./log/pageTaskFile.log
log4j.appender.pageTaskFile.Append = true
log4j.appender.pageTaskFile.Threshold = INFO
log4j.appender.pageTaskFile.layout = org.apache.log4j.PatternLayout
log4j.appender.pageTaskFile.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %F:%L %-16t - %m%n

这个最终被转为了:

调用代码:

1
2
Logger logger = Logger.getLogger("pageTask");
logger.info("aaa");

Logger 类控制的是一个大的方向,如果通过的话,才会进一步进入附属在 Appender 上的各个 Appender 进行打印日志。然后迭代对各个 Appender 进行 Threshold 验证,如果通过就打印,如果不通过就不打印。


寻找 Logger 的过程,如果找不到,最终会落到 rootLogger 上:

1
2
3
4
5
6
7
8
9
10
11
12
public class Category implements AppenderAttachable {

public Level getEffectiveLevel() {
for(Category c = this; c != null; c=c.parent) {
if(c.level != null) {
return c.level;
}
}
return null; // If reached will cause an NullPointerException.
}

}

声明如下的 log4j.properties 日志文件:

1
2
log4j.logger.com.buptnsrc.appcrawl.mapper = DEBUG, S
log4j.additivity.com.buptnsrc.appcrawl.mapper = false

则最终 Logger 的继承关系为:


additivity 的作用:

log4j 的性能问题

(1) log4j 1.2.18:

多个线程使用同一个 Logger 加锁:

多个线程使用同一个 Appender 加锁:

这两个锁对于系统的性能影响是很大的。

logback 两种日志过滤器

(1) 级别过滤器

级别过滤器: 根据级别进行精确匹配,如下只会输入 INFO 级别的日志到这个文件中,其他高于或者低于 INFO 级别的日志都不会输出到这个文件中。

1
2
3
4
5
6
7
8
9
<appender name="main_info" class="ch.qos.logback.core.rolling.RollingFileAppender">

<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>

</appender>

(2) 阈值过滤器:

阈值过滤器: 过滤掉指定级别以下的信息,如下所有低于 INFO 级别的日志都不会输出,但是高于 INFO 级别例如 ERROR、WARN 等日志信息依然会输出到这个文件中。

1
2
3
4
5
6
7
<appender name="ApkTaskFile" class="ch.qos.logback.core.rolling.RollingFileAppender">

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>

</appender>

property 属性的示例

log4j_property_example

推荐文章