【QCon】精华内容上线85%,全面覆盖“人工智能+”的典型案例!>>> 了解详情
写点什么

打印日志时 Logback 内部都做了些什么

  • 2019-07-23
  • 本文字数:3471 字

    阅读完需:约 11 分钟

打印日志时 Logback 内部都做了些什么

一、引言

Logback 是一个优秀的开源日志框架,我们很多项目都使用它来记录日志。实际使用时,通常仅需要一行语句即可记录相应的日志信息,如


logger.info("Hello world.");


那么,看似简单的语句背后都有哪些故事,打印日志时 Logback 内部都做了些什么?


本文以输出日志内容到文件为例,阐述 Logback 打印日志的工作流程。

二、Logback 设计

想要了解 Logback 打印日志的工作原理,首先需要清楚 Logback 所涉及的一些重要概念。


  • LoggingEvent

  • LoggingEvent 表示日志事件的概念,其中包括了所有与打印日志请求相关的参数,如当前请求线程、当前时间、消息内容、请求级别等。整个日志打印流程都围绕这个类来展开。

  • Logger

  • Logger 意为日志记录器,是打印日志的入口,打印日志时要先获取一个 Logger 对象。每个 Logger 对象都有一个名字,且名字遵循层次化的命名规则。如

  • 名为 “com.foo” 的 logger 是名为 “com.foo.Bar” 的 logger 的父级。root logger 位于 logger 层级的最顶端,是所有 logger 的祖先。

  • Appender

  • Logback 允许日志输出到多个目的地,Appender 表示目的地这个概念,常见的 appender 有控制台、文件、socket 服务器、数据库等。一个 logger 可以关联多个 appender。

  • Layout

  • Layout 负责对日志消息进行格式化,用户可以自主设置日志输出的格式。

  • 如,采用转换模式 “%-4relative [%thread] %-5level %logger{32} - %msg%n” 输出的日志格式如下:


176[main]DEBUG manual.architecture.HelloWorld-Helloworld.


其中,第一列表示时间戳,第二列表示日志请求线程,第三列表示请求级别,第四列表示请求的 logger 的名字,"-"之后的内容为具体的日志文本。


Logback 核心类图如下:


三、打印日志流程

清楚了 Logback 中的核心概念,下面开始介绍 Loback 打印日志流程。

3.1 获取 Logger

调用 org.slf4j.LoggerFactory 类的 getLogger 方法,即可获取 Logger 对象,如图。


Logger x = LoggerFactory.getLogger("wombat");Logger y = LoggerFactory.getLogger("wombat");
复制代码


相同名字对应的 Logger 对象相同,即 x,y 指向同一个对象。

3.2 调用 logger 打印方法

下面介绍调用 logger 的 info() 方法时做了哪些事情。

3.2.1 取得过滤链(filter chain)的判定结果

此处使用的过滤器类为 TurboFilter,TurboFilter 与日志上下文绑定,在日志事件(LoggingEvent)创建之前被调用,会过滤所有的日志请求。如果过滤链的判断结果为 FilterReply.DENY,则记录请求被抛弃。如果结果是 FilterReply.NEUTRAL,则继续下一步,即进入 2.2。如果结果是 FilterReply.ACCEPT,则忽略第二步, 直接进入第三步,即 2.3。

3.2.2 检查日志级别

对 logger 的有效级别与日志请求级别进行比较。如果请求级别数值小于有效级别,本次请求将


被禁用,Logback 会直接抛弃请求,不做进一步处理;否则,继续下一步。

3.2.3 创建 LoggingEvent 对象

只有到了这一步,logback 才会创建 LoggingEvent 对象,该对象包含所有与请求相关的参数,如请求用的 logger、请求级别、消息、请求携带的异常、当前时间、当前线程等。

3.2.4 调用 appenders 的 doAppend() 方法

在创建 LoggingEvent 对象以后,logback 将调用所有可用 appender 的 doAppend()方法,进行日志输出。


doAppender()方法会调用 appender 关联的过滤器,此处使用的过滤器类为 Filter,执行过滤链判定,


返回结果同 TurboFilter 判定结果,都是一个 FilterReply 枚举值。如果当前过滤器返回结果是 FilterReply.DENY,则记录请求被抛弃;如果结果是 FilterReply.NEUTRAL,则将日志事件交由过滤链中下一个过滤器来处理;如果结果是 FilterReply.ACCEPT,日志事件被立即处理,不再经过剩余的过滤器。

3.2.5 格式化日志信息

appender 在输出日志信息前,需要对日志事件(LoggingEvent)进行格式化。以 OutputStreamAppender 为例,它使用 Encoder 将日志事件转换为字节数组并把字节数组写出到相应的输出流,在转换为字节数组前,Encoder 通过调用 Layout 的 doLayout() 方法将日志事件格式化为字符串。

3.2.6 输出日志信息

日志信息格式化完成以后,将会输出到各个 appender 对应的目的地。


Logback 打印日志整体流程如下图:


四、额外的工作

日志输出到文件以后,会引出一些新的问题。如单个文件太大能否进行切割,能否对文件进行归档,超出一定时间的历史日志能否自动删除等。Logback 内部,RollingFileAppender 担此重任,用来处理这类问题。


RollingFileAppender 继承自 FileAppender,能够滚动记录文件,其内部依赖两个重要组件。一个是 RollingPolicy,负责滚动处理(rollover)。另一个是 TriggeringPolicy,决定是否滚动以及何时进行滚动处理。


项目中名为 “ERROR” 的 appender 配置如下,应用通过该 appender,将 ERROR 级别的日志输出到 error.log 文件中,同时,使用基于大小和时间的滚动策略来对 error.log 文件进行处理。


<appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">    <file>${LOG_PATH}/error.log</file>    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">        <level>ERROR</level>    </filter>    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">        <!-- daily rollover -->        <fileNamePattern>${LOG_PATH}/%d{yyyy-MM-dd}/error-%d{yyyy-MM-dd}-%i.log.gz</fileNamePattern>        <!-- each file should be at most 100MB -->        <maxFileSize>100MB</maxFileSize>        <!-- keep 60 days' worth of history capped at 3GB total size -->        <maxHistory>60</maxHistory>        <totalSizeCap>3GB</totalSizeCap>    </rollingPolicy>    <encoder>        <pattern>            %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %caller{1} - %msg%n        </pattern>        <charset>utf8</charset>    </encoder></appender>
复制代码


这里用到了 SizeAndTimeBasedRollingPolicy,它同时实现了 RollingPolicy 和 TriggeringPolicy,该类类图如下:



RollingFileAppender 在输出日志信息时,会调用一个 subAppend()方法,代码如下:


@Overrideprotected void subAppend(E event) {    synchronized (triggeringPolicy) {        if (triggeringPolicy.isTriggeringEvent(currentlyActiveFile, event)) {            rollover();        }    }    super.subAppend(event);}
复制代码


在同步代码块中,首先判断是否触发翻转操作,如果是,则对日志文件进行翻转处理。可见,日志翻转发生在打印日志时。这里翻转操作有两种情况。

4.1 基于文件大小滚动

如果当前日志文件大小超过了设置的 maxFileSize,会触发一次翻转操作,将当前文件归档,同时创建一个新的活动文件,用来输出日志。

4.2 基于时间滚动

Logback 在初始化时会设置一个滚动触发时间点,当到达该时间点以后,会触发一次翻转操作,同样将当前文件归档,同时创建一个新的活动文件,用来输出日志;此外,会按照 maxHistory 的设置对归档日志文件进行删除,若设置了 totalSizeCap,还会判断归档日志文件大小是否超过了该值,超过则会进行清理。清理工作由异步线程来进行,关键代码如下:


public class ArhiveRemoverRunnable implements Runnable {    Date now;    ArhiveRemoverRunnable(Date now) {        this.now = now;    }
@Override public void run() { clean(now); if (totalSizeCap != UNBOUNDED_TOTAL_SIZE_CAP && totalSizeCap > 0) { capTotalSize(now); } }}
复制代码

五、尾声

至此,Logback 打印日志到文件的工作流程就介绍完了。


翻阅 Logback 资料时,在官方 jira 上看到过一个问题:有个桌面应用使用 Logback 记录日志,该应用每天运行几次,但基本不会在凌晨使用;问题现象是应用配置了 maxHistory ,历史日志文件并没有被删除。经分析,是因为 Logback 滚动触发时间是在每次应用启动的时候进行设置,按天滚动就设置为第二天凌晨记录日志时触发,由于该应用只在白天运行,且每次启动都会重新设置触发时间,导致滚动策略永远不会触发,所以历史日志文件不会被删除。


在后面的版本中,Logback 在 TimeBasedRollingPolicy 中增加了 cleanHistoryOnStart 属性,配置为 true 以后,可以在应用启动时执行历史日志删除工作,解决了上述问题。


由此可见,任何优秀的系统都不是一蹴而就的,而是在满足业务场景的基础上不断迭代演化而来的。


本文转载自公众号有赞 coder(ID:youzan_coder)


原文链接


https://mp.weixin.qq.com/s/zwZ4yUuj7iEXnzwM1RBPBA


2019-07-23 08:003976

评论

发布
暂无评论
发现更多内容

SpringCloud Alibaba微服务实战九 - Seata 容器化

AI乔治

Java 架构 微服务 Spring Cloud

SpringCloud Alibaba微服务实战十 - 服务网关SpringCloud Gateway

AI乔治

Java 架构 微服务 Spring Cloud

《华为数据之道》读书笔记:第 2 章 建立企业级数据综合治理体系

方志

数据中台 数据仓库 数字化转型 数据治理

第一周 架构方法 作业一 「架构师训练营 3 期」

胡云飞

极客大学架构师训练营 架构方法

面试专题-Java基础面试技术

洛神灬殇

MySQL如何实现万亿级数据存储?

冰河

MySQL 分布式 微服务 高可用 mycat

SpringCloud Alibaba微服务实战八 - Seata 整合Nacos

AI乔治

Java 架构 微服务 Spring Cloud

面试 | 程序猿面试,Elasticsearch被坑被虐的体无完肤...

Java架构师迁哥

架构师训练营第九周作业

四夕晖

一次带你全面解析Nginx,从安装JDK开始讲起,收藏当手册

996小迁

Java 学习 编程 架构 面试

Docker基础与实战,看这一篇就够了

AI乔治

Java Docker spring 架构

字节跳动总监总结的开发笔记火了!在知乎上已超5000赞!

Java架构师迁哥

经典之作——《数学之美》第二版-吴军

计算机与AI

数学

百度的五年乌镇行旅:AI如何穿越过漫漫时光,成为世界的发展新动能?

脑极体

他在滕王阁上醒来,见到智慧视觉第一城

脑极体

SpringCloud Alibaba微服务实战六 - 配置隔离

AI乔治

Java 架构 微服务 Spring Cloud

SpringCloud Alibaba微服务实战七 - 分布式事务

AI乔治

Java 架构 微服务 Spring Cloud

区块链农产品溯源解决方案,农产品追溯系统价格

13530558032

区块链+数字版权:区块链助力版权保护

13530558032

折半查找和插值查找

ilovealt

算法和数据结构

架构师训练营第 1 期 - 第 9 周 - 命题作业

wgl

年轻人不讲武德!Security五套「源码级」笔记哪里来的?

小Q

学习 编程 面试 spring security SpringCloud

SpringCloud Alibaba微服务实战五 - 限流熔断

AI乔治

Java 架构 微服务 Spring Cloud

架构师训练营第 1 期 - 第 9 周 - 学习总结

wgl

极客大学架构师训练营

耗子尾汁,你居然还不懂什么是架构师?那你编码为了什么?还不看阿里人怎么判定吗?

小Q

Java 学习 编程 架构 面试

从前世今生聊一聊,大厂为啥亲睐时序数据库

华为云开发者联盟

数据库 场景 时序

对话机器人70年:科幻与现实的交融

华为云开发者联盟

AI 机器人 对话

图解 | 不得错过的Binder浅析(二)

哈利迪

android

甲方日常 56

句子

工作 随笔杂谈 日常

如何在ForeSpider数据采集器中设置代理IP

前嗅大数据

大数据 爬虫 数据采集 代理IP 代理IP设置

智慧公安二维码报警定位系统,高速路二维码定位报警开发

13530558032

打印日志时 Logback 内部都做了些什么_开源_百川_InfoQ精选文章