为什么使用 logback
记得前几年工作的时候, 公司使用的日志框架还是 log4j, 大约从 16 年中到现在, 不管是我参与的别人已经搭建好的项目还是我自己主导的项目, 日志框架基本都换成了 logback, 总结一下, logback 大约有以下的一些优点:
内核重写测试充分初始化内存加载更小, 这一切让 logback 性能和 log4j 相比有诸多倍的提升
logback 非常自然地直接实现了 slf4j, 这个严格来说算不上优点, 只是这样, 再理解 slf4j 的前提下会很容易理解 logback, 也同时很容易用其他日志框架替换 logback
logback 有比较齐全的 200 多页的文档
logback 当配置文件修改了, 支持自动重新加载配置文件, 扫描过程快且安全, 它并不需要另外创建一个扫描线程
支持自动去除旧的日志文件, 可以控制已经产生日志文件的最大数量
总而言之, 如果大家的项目里面需要选择一个日志框架, 那么我个人非常建议使用 logback
logback 加载
我们简单分析一下 logback 加载过程, 当我们使用 logback-classic.jar 时, 应用启动, 那么 logback 会按照如下顺序进行扫描:
在系统配置文件 System Properties 中寻找是否有 logback.configurationFile 对应的 value
在 classpath 下寻找是否有 logback.groovy(即 logback 支持 groovy 与 xml 两种配置方式)
在 classpath 下寻找是否有 logback-test.xml
在 classpath 下寻找是否有 logback.xml
以上任何一项找到了, 就不进行后续扫描, 按照对应的配置进行 logback 的初始化, 具体代码实现可见 ch.qos.logback.classic.util.ContextInitializer 类的 findURLOfDefaultConfigurationFile 方法
当所有以上四项都找不到的情况下, logback 会调用 ch.qos.logback.classic.BasicConfigurator 的 configure 方法, 构造一个 ConsoleAppender 用于向控制台输出日志, 默认日志输出格式为 "%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"
logback 的 configuration
logback 的重点应当是 AppenderLoggerPattern, 在这之前先简单了解一下 logback 的 < configuration>,<configuration > 只有三个属性:
scan: 当 scan 被设置为 true 时, 当配置文件发生改变, 将会被重新加载, 默认为 true
scanPeriod: 检测配置文件是否有修改的时间间隔, 如果没有给出时间单位, 默认为毫秒, 当 scan=true 时这个值生效, 默认时间间隔为 1 分钟
debug: 当被设置为 true 时, 将打印出 logback 内部日志信息, 实时查看 logback 运行信息, 默认为 false
<logger > 与 < root>
先从最基本的 < logger > 与 < root > 开始
<logger > 用来设置某一个包或者具体某一个类的日志打印级别以及指定 < appender><logger > 可以包含零个或者多个 < appender-ref > 元素, 标识这个 appender 将会添加到这个 logger<logger > 仅有一个 name 属性一个可选的 level 属性和一个可选的 additivity 属性:
name: 用来指定受此 logger 约束的某一个包或者具体的某一个类
level: 用来设置打印级别, 五个常用打印级别从低至高依次为 TRACEDEBUGINFOWARNERROR, 如果未设置此级别, 那么当前 logger 会继承上级的级别
additivity: 是否向上级 logger 传递打印信息, 默认为 true
<root > 也是 < logger > 元素, 但是它是根 logger, 只有一个 level 属性, 因为它的 name 就是 root
接着写一段代码来测试一下:
- public class Slf4jTest {
- @Test
- public void testSlf4j() {
- Logger logger = LoggerFactory.getLogger(Object.class);
- logger.trace("=====trace=====");
- logger.debug("=====debug=====");
- logger.info("=====info=====");
- logger.warn("=====warn=====");
- logger.error("=====error=====");
- }
- }
logback.xml 的配置为:
- <?xml version="1.0" encoding="UTF-8" ?>
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <layout class="ch.qos.logback.classic.PatternLayout">
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </layout>
- </appender>
- <root level="info">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
root 将打印级别设置为 "info" 级别,<appender > 暂时不管, 控制台的输出为:
- 2018-03-26 22:57:48.779 [main] INFO java.lang.Object - =====info=====
- 2018-03-26 22:57:48.782 [main] WARN java.lang.Object - =====warn=====
- 2018-03-26 22:57:48.782 [main] ERROR java.lang.Object - =====error=====
logback.xml 的意思是, 当 Test 方法运行时, root 节点将日志级别大于等于 info 的交给已经配置好的名为 "STDOUT" 的 < appender > 进行处理,"STDOUT" 将信息打印到控制台上
接着理解一下 < logger > 节点的作用, logback.xml 修改一下, 加入一个只有 name 属性的 < logger>:
- <?xml version="1.0" encoding="UTF-8" ?>
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <layout class="ch.qos.logback.classic.PatternLayout">
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </layout>
- </appender>
- <logger name="java" />
- <root level="debug">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
注意这个 name 表示的是 LoggerFactory.getLogger(XXX.class),XXX 的包路径, 包路径越少越是父级, 我们测试代码里面是 Object.class, 即 name="java" 是 name="java.lang" 的父级, root 是所有 < logger > 的父级看一下输出为:
- 2018-03-27 23:02:02.963 [main] DEBUG java.lang.Object - =====debug=====
- 2018-03-27 23:02:02.965 [main] INFO java.lang.Object - =====info=====
- 2018-03-27 23:02:02.966 [main] WARN java.lang.Object - =====warn=====
- 2018-03-27 23:02:02.966 [main] ERROR java.lang.Object - =====error=====
出现这样的结果是因为:
<logger > 中没有配置 level, 即继承父级的 level,<logger > 的父级为 < root>, 那么 level=debug
没有配置 additivity, 那么 additivity=true, 表示此 < logger > 的打印信息向父级 < root > 传递
没有配置 < appender-ref>, 表示此 < logger > 不会打印出任何信息
由此可知,<logger > 的打印信息向 < root > 传递,<root > 使用 "STDOUT" 这个 < appender > 打印出所有大于等于 debug 级别的日志举一反三, 我们将 < logger > 的 additivity 配置为 false, 那么控制台应该不会打印出任何日志, 因为 < logger > 的打印信息不会向父级 < root > 传递且 < logger > 没有配置任何 < appender>, 大家可以自己试验一下
接着, 我们再配置一个 < logger>:
- <?xml version="1.0" encoding="UTF-8" ?>
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <layout class="ch.qos.logback.classic.PatternLayout">
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </layout>
- </appender>
- <logger name="java" additivity="false" />
- <logger name="java.lang" level="warn">
- <appender-ref ref="STDOUT" />
- </logger>
- <root level="debug">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
如果读懂了上面的例子, 那么这个例子应当很好理解:
LoggerFactory.getLogger(Object.class), 首先找到 name="java.lang" 这个 < logger>, 将日志级别大于等于 warn 的使用 "STDOUT" 这个 < appender > 打印出来
name="java.lang" 这个 < logger > 没有配置 additivity, 那么 additivity=true, 打印信息向上传递, 传递给父级 name="java" 这个 < logger>
name="java" 这个 < logger > 的 additivity=false 且不关联任何 < appender>, 那么 name="java" 这个 < appender > 不会打印任何信息
由此分析, 得出最终的打印结果为:
- 2018-03-27 23:12:16.147 [main] WARN java.lang.Object - =====warn=====
- 2018-03-27 23:12:16.150 [main] ERROR java.lang.Object - =====error=====
举一反三, 上面的 name="java" 这个 < appender > 可以把 additivity 设置为 true 试试看是什么结果, 如果对前面的分析理解的朋友应该很容易想到, 有两部分日志输出, 一部分是日志级别大于等于 warn 的一部分是日志级别大于等于 debug 的
<appender>
接着看一下 < appender>,<appender > 是 < configuration > 的子节点, 是负责写日志的组件 < appender > 有两个必要属性 name 和 class:
name 指定 < appender > 的名称
class 指定 < appender > 的全限定名
<appender > 有好几种, 上面我们演示过的是 ConsoleAppender,ConsoleAppender 的作用是将日志输出到控制台, 配置示例为:
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <encoder>
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </encoder>
- </appender>
其中, encoder 表示对参数进行格式化我们和上一部分的例子对比一下, 发现这里是有所区别的, 上面使用了 < layout > 定义 < pattern>, 这里使用了 < encoder > 定义 < pattern>, 简单说一下:
<encoder > 是 0.9.19 版本之后引进的, 以前的版本使用 < layout>,logback 极力推荐的是使用 < encoder > 而不是 < layout>
最常用的 FileAppender 和它的子类的期望是使用 < encoder > 而不再使用 < layout>
关于 < encoder > 中的格式下一部分再说接着我们看一下 FileAppender,FileAppender 的作用是将日志写到文件中, 配置示例为:
- <appender name="FILE" class="ch.qos.logback.core.FileAppender">
- <file>D:/123.log</file>
- <append>true</append>
- <encoder>
- <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
- </encoder>
- </appender>
它的几个节点为:
<file > 表示写入的文件名, 可以使相对目录也可以是绝对目录, 如果上级目录不存在则自动创建
<appender > 如果为 true 表示日志被追加到文件结尾, 如果是 false 表示清空文件
<encoder > 表示输出格式, 后面说
<prudent > 如果为 true 表示日志会被安全地写入文件, 即使其他的 FileAppender 也在向此文件做写入操作, 效率低, 默认为 false
接着来看一下 RollingFileAppender,RollingFileAppender 的作用是滚动记录文件, 先将日志记录到指定文件, 当符合某个条件时再将日志记录到其他文件, RollingFileAppender 配置比较灵活, 因此使用得更多, 示例为:
- <appender name="ROLLING-FILE-1" class="ch.qos.logback.core.rolling.RollingFileAppender">
- <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
- <fileNamePattern>rolling-file-%d{yyyy-MM-dd}.log</fileNamePattern>
- <maxHistory>30</maxHistory>
- </rollingPolicy>
- <encoder>
- <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
- </encoder>
- </appender>
这种是仅仅指定了 < rollingPolicy > 的写法,<rollingPolicy > 的作用是当发生滚动时, 定义 RollingFileAppender 的行为, 其中上面的 TimeBasedRollingPolicy 是最常用的滚动策略, 它根据时间指定滚动策略, 既负责滚动也负责触发滚动, 有以下节点:
<fileNamePattern>, 必要节点, 包含文件名及 "%d" 转换符,"%d" 可以包含一个 Java.text.SimpleDateFormat 指定的时间格式, 如 %d{yyyy-MM}, 如果直接使用 %d 那么格式为 yyyy-MM-ddRollingFileAppender 的 file 子节点可有可无, 通过设置 file 可以为活动文件和归档文件指定不同的位置
<maxHistory>, 可选节点, 控制保留的归档文件的最大数量, 如果超出数量就删除旧文件, 假设设置每个月滚动且 < maxHistory > 是 6, 则只保存最近 6 个月的文件
向其他还有 SizeBasedTriggeringPolicy, 用于按照文件大小进行滚动, 可以自己查阅一下资料
异步写日志
日志通常来说都以文件形式记录到磁盘, 例如使用 < RollingFileAppender>, 这样的话一次写日志就会发生一次磁盘 IO, 这对于性能是一种损耗, 因此更多的, 对于每次请求必打的日志 (例如请求日志, 记录请求 API 参数请求时间), 我们会采取异步写日志的方式而不让此次写日志发生磁盘 IO, 阻塞线程从而造成不必要的性能损耗 (不要小看这个点, 可以网上查一下服务端性能优化的文章, 只是因为将日志改为异步写, 整个 QPS 就有了大幅的提高)
接着我们看下如何使用 logback 进行异步写日志配置:
- <?xml version="1.0" encoding="UTF-8" ?>
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <encoder>
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </encoder>
- </appender>
- <appender name="ROLLING-FILE-1" class="ch.qos.logback.core.rolling.RollingFileAppender">
- <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
- <fileNamePattern>D:/rolling-file-%d{yyyy-MM-dd}.log</fileNamePattern>
- <maxHistory>30</maxHistory>
- </rollingPolicy>
- <encoder>
- <pattern>%-4relative [%thread] %-5level %lo{35} - %msg%n</pattern>
- </encoder>
- </appender>
- <!-- 异步输出 -->
- <appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">
- <!-- 不丢失日志. 默认的, 如果队列的 80% 已满, 则会丢弃 TRACTDEBUGINFO 级别的日志 -->
- <discardingThreshold>0</discardingThreshold>
- <!-- 更改默认的队列的深度, 该值会影响性能. 默认值为 256 -->
- <queueSize>256</queueSize>
- <!-- 添加附加的 appender, 最多只能添加一个 -->
- <appender-ref ref ="ROLLING-FILE-1"/>
- </appender>
- <logger name="java" additivity="false" />
- <logger name="java.lang" level="DEBUG">
- <appender-ref ref="ASYNC" />
- </logger>
- <root level="INFO">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
即, 我们引入了一个 AsyncAppender, 先说一下 AsyncAppender 的原理, 再说一下几个参数:
当我们配置了 AsyncAppender, 系统启动时会初始化一条名为 "AsyncAppender-Worker-ASYNC" 的线程
当 Logging Event 进入 AsyncAppender 后, AsyncAppender 会调用 appender 方法, appender 方法中再将 event 填入 Buffer(使用的 Buffer 为 BlockingQueue, 具体实现为 ArrayBlockingQueye) 前, 会先判断当前 Buffer 的容量以及丢弃日志特性是否开启, 当消费能力不如生产能力时, AsyncAppender 会将超出 Buffer 容量的 Logging Event 的级别进行丢弃, 作为消费速度一旦跟不上生产速度导致 Buffer 溢出处理的一种方式
上面的线程的作用, 就是从 Buffer 中取出 Event, 交给对应的 appender 进行后面的日志推送
从上面的描述我们可以看出, AsyncAppender 并不处理日志, 只是将日志缓冲到一个 BlockingQueue 里面去, 并在内部创建一个工作线程从队列头部获取日志, 之后将获取的日志循环记录到附加的其他 appender 上去, 从而达到不阻塞主线程的效果因此 AsyncAppender 仅仅充当的是事件转发器, 必须引用另外一个 appender 来做事
从上述原理, 我们就能比较清晰地理解几个参数的作用了:
discardingThreshold, 假如等于 20 则表示, 表示当还剩 20% 容量时, 将丢弃 TRACEDEBUGINFO 级别的 Event, 只保留 WARN 与 ERROR 级别的 Event, 为了保留所有的 events, 可以将这个值设置为 0, 默认值为 queueSize/5
queueSize 比较好理解, BlockingQueue 的最大容量, 默认为 256
includeCallerData 表示是否提取调用者数据, 这个值被设置为 true 的代价是相当昂贵的, 为了提升性能, 默认当 event 被加入 BlockingQueue 时, event 关联的调用者数据不会被提取, 只有线程名这些比较简单的数据
appender-ref 表示 AsyncAppender 使用哪个具体的 < appender > 进行日志输出
<encoder>
<encoder > 节点负责两件事情:
把日志信息转换为字节数组
把字节数组写到输出流
目前 PatternLayoutEncoder 是唯一有用的且默认的 encoder, 有一个 < pattern > 节点, 就像上面演示的, 用来设置日志的输入格式, 使用 % 转换符 "的方式, 如果要输出"%"则必须使用"\%"对"%" 进行转义
<encoder > 的一些可用参数用表格表示一下:
转换符 | 作 用 | 是否避免使用 |
c{length} lo{length} logger{length} | 输出日志的 logger 名称,可有一个整型参数来缩短 & lt;logger> 名称,有几种情况: 1、不输入表示输出完整的 & lt;logger> 名称 2、输入 0 表示只输出 & lt;logger> 最右边点号之后的字符串 3、输入其他数字表示输出小数点最后边点号之前的字符数量 | 否 |
C{length} class{length} | 输出指定记录的请求的调用者的全限定名,length 同上 | 是 |
d{pattern} date{pattern} | 输出时间格式,模式语法同 java.text.SimpleDateFormat 兼容 | 否 |
caller{depth} | 输出生成日志的调用者的位置信息,整数选项表示输出信息深度 | 否 |
L | 输出执行日志的请求行号 | 是 |
m msg message | 输出应用程序提供的信息 | 否 |
m | 输入执行日志请求的方法名 | 是 |
n | 输出平台相关的分行符 "\n" 或者 "\r\n",即换行 | 否 |
p le level | 输出日志级别 | 否 |
r relative | 输出从程序启动到创建日志记录的时间,单位为毫秒 | 否 |
t thread | 输出产生日志的线程名称 | 否 |
看到最后一列是 "是否避免使用", 这是因为这些信息是无法直接拿到的 (比如请求行号调用方法名),logback 必须通过一些特殊手段去获取这些数据 (比如在日志打印出产生一个堆栈信息), 这种操作会比较影响效率, 因此除非必要, 否则不建议打印这些数据
Filter
最后来看一下 < filter>,<filter > 是 < appender > 的一个子节点, 表示在当前给到的日志级别下再进行一次过滤, 最基本的 Filter 有 ch.qos.logback.classic.filter.LevelFilter 和 ch.qos.logback.classic.filter.ThresholdFilter, 首先看一下 LevelFilter:
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <encoder>
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </encoder>
- <filter class="ch.qos.logback.classic.filter.LevelFilter">
- <level>WARN</level>
- <onMatch>ACCEPT</onMatch>
- <onMismatch>DENY</onMismatch>
- </filter>
- </appender>
- <logger name="java" additivity="false" />
- <logger name="java.lang" level="DEBUG">
- <appender-ref ref="STDOUT" />
- </logger>
- <root level="INFO">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
看一下输出:
2018-03-31 22:22:58.843 [main] WARN java.lang.Object - =====warn=====
看到尽管 < logger > 配置的是 DEBUG, 但是输出的只有 warn, 因为在 < filter > 中对匹配到 WARN 级别时做了 ACCEPT(接受), 对未匹配到 WARN 级别时做了 DENY(拒绝), 当然只能打印出 WARN 级别的日志
再看一下 ThresholdFilter, 配置为:
- <?xml version="1.0" encoding="UTF-8" ?>
- <configuration scan="false" scanPeriod="60000" debug="false">
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <encoder>
- <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
- </encoder>
- <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
- <level>INFO</level>
- </filter>
- </appender>
- <logger name="java" additivity="false" />
- <logger name="java.lang" level="DEBUG">
- <appender-ref ref="STDOUT" />
- </logger>
- <root level="INFO">
- <appender-ref ref="STDOUT" />
- </root>
- </configuration>
看一下输出为:
- 2018-03-31 22:41:32.353 [main] INFO java.lang.Object - =====info=====
- 2018-03-31 22:41:32.358 [main] WARN java.lang.Object - =====warn=====
- 2018-03-31 22:41:32.359 [main] ERROR java.lang.Object - =====error=====
因为 ThresholdFilter 的策略是, 会将日志级别小于 < level > 的全部进行过滤, 因此虽然指定了 DEBUG 级别, 但是只有 INFO 及以上级别的才能被打印出来
来源: https://www.cnblogs.com/xrq730/p/8628945.html