希望用易懂的方式讲解如何使用 Log4j 来管理 Java 程序的日志
动机
最近在工作中遇到了日志文件占用过多磁盘空间的状况。
具体来说是:一个运行在服务器上的 Java 程序每日生成 1.5 GB 的日志,而那台服务器的硬盘容量只有 150GB,所以程序上线运行几个月后磁盘空间就满了。
因为程序已经使用 Log4j 来生成日志,所以解决方式是配置启用了 Log4j 的轮转模式 (Rotation)。
在日志轮转的基础上,我还启用了 Log4j 另外两个很有用的小功能,也将在文章最后提及。
这篇文章将 讲解如何配置 Log4j 和实现日志轮转的方式。
阅读前须知 / Prerequisite
这篇文章主要写给 已经在 Java 程序中使用 Log4j 生成日志,但想了解 / 配置轮转模式 的开发者。
而对于 仍还未使用过 Log4j 的读者,那么这篇文章会缺少 Log4j 的使用细节。
在讲解如何设置 Log4j 的日志轮转之前,我想先简单介绍 Log4j 的XML配置文件。
配置文件包含了记录器和输出器的定义,而日志轮转实际上是由一个特殊的输出器来实现的。
我将尽可能地把英文翻译成中文,比如 Configuration - 配置,Logger - 记录器,Appender - 输出器 。
导入依赖库
Log4j 是一个第三方的库,所以需要下载并把它导入项目。
企业的 Java 项目通常使用一些项目编译工具,常见的有 Maven 和 Gradle。它们能自动下载需要的库,并把它们和我们的项目代码一同编译。
我的项目用的是 Gradle,所以添加这两行到 build.gradle 文件中的 dependencies 里。
dependencies {
compile group: 'org.apache.logging.log4j', name: 'log4j-api', version: '2.12.1'
compile group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.12.1'
}
注意,这里我们用的是 2.0 以上的版本。
如果你用的是其他包管理工具,导入方式可以参考官网
当然啦,如果没有用任何工具,也可以在官网下载 Jar 文件,在 Classpath 中手动添加他们的完整路径。
系统参数
这篇文章的讲解将基于用 XML 文件来设置 Log4j 的日志功能。
(如果你想写代码来配置 Log4j ,那么这里的部分概念和原理的讲解依然值得参考)
首先在我们的项目里,创建 log4j2.xml
文件,如果你们的项目已经有专门放配置文件的目录,比如Config 或者 Configurations
,那就放这个目录下。如果你的项目已经有 log4j2.xml
则不必新建啦。
那么程序运行时怎么知道去哪找这个文件呢 ?答案是通过系统属性 / System Property。
最简单的做法是在程序启动时传入这个参数:
-Dlog4j2.configurationFile=/[完整路径]/log4j2.xml
参数的前缀-D
意味着:虚拟机将定义一个名叫 log4j2.configurationFile
系统属性,供程序运行时查询它。
如果你也用 IDE 开发的话,可以在运行配置 (Run / Debug Configuration) 里可以找到 VM options
, 把这个参数加入,这样在 IDE 运行程序时也将利用 Log4j 的配置。
因为人们通常希望在开发和测试时使用不同的日志生成方式,常常会创建多个配置文件。Log4j 也能够在不同条件下使用不同的配置文件的,但这篇文章并不涉及。
如果你想了解 Log4j 具体如何查找配置文件,可以阅读这个文档。
配置文件
前一节里我们创建了log4j2.xml
,并让程序获知了它的位置,现在我们要编写配置文件啦。
官网的入门教程会提供一个最基础的配置文件,大概是这样的。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
不论多复杂的配置文件都将是同样的结构,它们都有这几个组成部分:
Configuration, Appenders 和 Loggers。
因为配置文件的格式是 XML ,第一行涵盖了当前 XML 文件的基本信息。
配置 / Configuration
可以这么想,Log4j 库每次启动时都会构建一个配置对象,其中存着各种配置信息:日志的生成格式,日志文件怎么命名,是否轮转,等等。
而我们所写的配置文件也就是在描述这个对象,所以最外层是 Configuration。
它有一个 status 属性,值可以是 TRACE, DEBUG 等等,表示 Log4j 运行时本身生成的日志的详细程度。
你可以把它设置成 DEBUG,随后在命令行运行时将看到 Log4j 的一些运行细节,比如往哪个文件写入了多少日志信息,日志是从哪些类 / 对象生成的,等等。
输出器 / Appenders
我们必须 至少定义一个输出器,这样程序运行时,日志才能被写到某个地方供之后查看。
可以这么理解,每个输出器定义了 它们接收到日志信息后
1)以什么样的格式(是否加上时间戳日期等等)写出去,和
2)写到哪。可以是控制台,也可以是文件,甚至是网络通道 / Socket。
复杂的项目往往有多个输出器,将日志写往不同的地方。
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
比如在最基础的配置文件中,有一个名叫 Console / 控制台 的输出器。
它包含一个 PatternLayout,它的 pattern 属性定义了日志中每一行信息的格式,比如按照这里的定义,输入日志的每一行都将有时间信息,信息分级 / level,和最后的日志信息本身,将出现在 %msg 的位置。
那么这个控制台输出器将日志写到哪呢 ?从它的 target 属性 能看出,是进程的标准输出。
另外,有读者可能想问这个不是叫 Console 吗,怎么不叫 XXAppender 呢 ?实际上,每一个输出器组件的名称对应了 Log4j 包中的一个类的名称,可以把它们看作是实现了 Appender 接口的的类。
如果能读到 Log4j 的源代码的话,就能找到一个叫 Console 的类。当然啦,Log4j 也支持导入我们自己写的输出器,具体见官网。
另外,我们可以通过 name 属性值设置名字,在 Logger 中的 AppenderRef 将指向它,稍后会讲到。
<Loggers>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
记录器 / Loggers
每个记录器定义了不同级别和来源的信息将被送往哪个输出器。通常我们也会有多个记录器。
最基础的配置里,我们会有一个 Root / 根记录器,意味着所有的信息都将经过它。它的定义也很简单粗暴,只要日志信息的级别是 ‘错误’,都将被送往控制台输出器,
我们因此能够在程序运行时,在控制台 (进程默认的标准输出) 只会看到错误信息,其他信息则被不输出。
要注意的是,每个记录器内都有一个 AppenderRef,它的 ref 属性值必须对应输出器的 name 属性。
轮转输出器 / Rolling Appender
介绍完配置文件中的几个基本组成后,终于可以开始讲讲如何设置轮转模式啦。
还记得吗,真正决定了日志信息如何被写和被写到哪的是 输出器 。这里我们就要用到 Log4j 提供的一个叫 RollingRandomAccessFile 的输出器啦,你可以把 Appenders 中的 Console 组件替换成下面这个。
<Appenders>
<RollingRandomAccessFile name="fileAppender">
<!-- 内容随后添加 -->
</RollingRandomAccessFile>
</Appenders>
日志轮转 / Log Rotation
这个做法 / 技术起源于这样一个情景。想象一下,我们在命令行里像这样启动了程序,随后便不再管它。
./my_program.sh > program.log &
那么程序运行时生成的所有日志信息都将被写到这个 program.log
文件中。如果程序的日志信息很多,那么可能没多久后日志文件就变得非常大,比如达到数个千兆 / GB的大小。
这样当我们想阅读 / 查找某些日志信息时,将非常困难,因为这意味着文本阅读器要将很大的文件加载到内存,而在数百兆的文件中搜索字符串也将比较耗时。
日志轮转的做法随之出现:人们就把日志信息按时间放到不同的文件里,比如今天晚上7点到9点的日志将被分别放到这三个文件里。
program.log.2019-08-21-19
program.log.2019-08-21-20
program.log.2019-08-21-21
这样人们想要阅读日志信息时,也能直接定位到具体时间段的日志。通常人们要查看日志的原因就是程序出错了,而对于程序出错的时间,人们总是有大概估计的。
旧日志管理
日志轮转 / 按时间来分类日志文件的另一个好处是,管理旧日志和清理不需要的日志变得方便许多。
比如,我们知道哪些文件里存的是若干天 / 月前的程序日志,将它们删除,获得更多可用的硬盘空间。
我们也可以每天都将一天前的日志自动压缩,减小硬盘空间占用。
当然,在多少天前的 / 什么样的日志是没用的这个问题上,不同程序和不同人都有不同的理解。
配置轮转输出器
现在我们就要配置之前加到 Appenders 内的这个 RollingRandomAccessFile 输出器啦。
首先可以在它的内部加上 PatternLayout,定义每行条日志信息的被输出的格式,向上文的 Console 里那样。
然后要加的是两个重要属性 fileName 和 filePattern,我将逐一介绍。
fileName
这个表示的是在下一次的轮转发生以前,当下日志将被写到的文件的路径,也可以把它称作 当前日志文件
那么轮转什么时候会发生呢,随后会讲到,我们可以自定义轮转触发的条件,比如时间。
filePattern
它表示轮转发生之后,当前日志文件 将被重命名成什么。如果我们像下面这样定义它们,
<RollingRandomAccessFile name="fileAppender"
fileName="app-name.log"
filePattern="app-name.log.%d{yyyy-MM-dd-HH}" >
<PatternLayout
pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" />
<RollingRandomAccessFile/>
比如我们在19点启动了程序,运行后 log4j 将立刻生成这个文件,里面存着不断增加的日志信息。
app-name.log
假设我们定义了按小时轮转 (下一节讲解),那么在20点时,app-name.log
将被清空,它的内容被移到这:
app-name.log.2019-08-21-19
它将包含着从程序19点运行开始,一直到 20:00 所产生的所有日志信息。
也可以这样想,在 20:00 时,log4j 把之前的 app-name.log
重命名成了 app-name.log.2019-08-21-19
,再把 app-name.log
清空以接收 20:00 之后的日志。这也就是日志轮转的具体结果。
再过若干个小时,我们也就能看到更多的日志文件啦。
app-name.log.2019-08-21-20
app-name.log.2019-08-21-21
..
轮转触发条件 / Triggering Policy
我们通过 fileName 和 filePattern 定义了日志轮转前后的命名方式,现在要定义轮转发生的条件啦。
最简单直接的方式就是按时间触发是日志轮转。
把TimeBasedTriggeringPolicy
加入 RollingRandomAccessFile
里。
<RollingRandomAccessFile>
<!-- 省略了其他内容 -->
<TimeBasedTriggeringPolicy />
</RollingRandomAccessFile>
需要注意的是,如果只按时间轮转日志,这个是一定要加的,因为 Log4j 并没有默认的轮转条件。
可以尝试一下把这行注释掉,将配置的 status 设为 DEBUG,再启动程序,将看到 Log4j 报错。
你可能想问,这一行什么好像什么也没说啊,如果我想每分钟轮转一次,该怎么配置呢?
Log4j 在这方面比较智能,它将根据 filePattern 中定义的文件名格式来判断轮转的具体频率。
也就是说,如果我们把它改为下面这样,日志轮转就会每分钟发生一次啦。
filePattern="app-name.log.%d{yyyy-MM-dd-HH-mm}"
根据日志容量轮转
也有时候人们觉得,简短的日志文件查看起来更方便一些,就希望当日志文件积累到一定大小时再轮转。
那么应对这种需求,可以用的就是 SizeBasedTriggeringPolicy
,把它加入输出器内就好啦。
它的 size 属性值定义了日志达到多少容量后将触发轮转,可以是 “4 KB” 也可以是 “1 GB“ 。
也可以把它看作,每个日志文件占用空间的上限。
<RollingRandomAccessFile>
<!-- 省略了属性等等 -->
<SizeBasedTriggeringPolicy size="16 KB" />
</Policies>
那么你可能想问了,按容量触发的轮转发生后,生成的文件叫什么呢 ?这仍取决于 filePattern。
举个例子,如果轮转每 16 KB 发生一次,而程序在19点和20点之间生成了33KB的日志。
如果用之前的 filePattern="app.log.%d{yyyy-MM-dd-HH}"
定义,最终只会两个文件。
app-name.log
app-name.log.2019-08-21-19
具体发生了什么呢 ?
一开始,最早的 16KB 日志信息被陆续写到 app-name.log
中,当它达到 16KB 时,第一次轮转触发。
app-name.log.2019-08-21-19
被创建来存储这 16KB 的日志信息。
app-name.log
此时被清空,开始存储接下来的 16KB 日志。当它再次达到 16KB 时,触发第二次轮转。
Log4j 将查看 filePattern 和当下的时间,发现这会儿还是19点。
它的决策是 把此时积累的 16KB (又一次) 轮转到 app-name.log.2019-08-21-19
。
因而最初的16KB日志被抹去。app-name.log
再次被清空,接收最后的 1KB 信息。
日志丢失
SizeBasedTriggeringPolicy
和 按照时间定义的 filePattern
实际上是在向 Log4j 表明这样的需求:
我们只希望在这个时间段内最多保留这个容量的日志信息,把最新的那部分留着就行了。
而我们既希望控制单个日志文件大小,有希望保留所有日志,就应该换个方式定义 filePattern 嘛,比如
filePattern="app-name.log.%i"
这里的 %i
在程序运行时会被替换成 轮转的次数,比如第一次轮转生成的就是 app-name.log.1
文件。
而轮转次数则可以通过这个 max 属性来定义的。
<DefaultRolloverStrategy max="100" />
随着日志轮转次数的增加,这个变量是不断增加的,Log4j 也就不会再把轮转日志覆写到已存在的文件里啦。
当然啦,我们仍然能给日志文件添上保留时间信息,像这样
filePattern="app-name.log.%d{yyyy-MM-dd-HH}.%i"
要注意的是,这个配置方式依然声明着: 这个时间段内最多保留这个容量的日志信息。
比如说,当 max 设为20时,在同一个时间戳上 (同一小时内),变量最多能增到 20。
这一小时里我们最多只会有20个日志文件,当有更多日志信息时,Log4j 依然会抛弃最旧的信息。
Default Rollover Strategy
人啊,就是要求多。还有一种常见需求是 希望最多保留N个日志文件。
这时候需要的就是把 DefaultRolloverStrategy
加到我们的输出器内。
它的 max
属性定义了最多保留多少最新的轮转日志文件。
<RollingRandomAccessFile>
<!-- 省略了属性等等 -->
<DefaultRolloverStrategy max="2" />
</RollingRandomAccessFile>
举个例子,比如我们把 max
设为 2,同时把SizeBasedTriggeringPolicy
中的 size
1 KB。
假如我们的程序将生成 4KB 的日志 / 4个千字节块,那么运行完我们将得到这3个文件
# 最后生成的1KB / 最新的那1KB日志信息
app-name.log
# 第2个千字节块
app-name.log.1
# 第3个千字节块
app-name.log.2
也就是说,最旧的 / 第一个千字节块 将被抛弃掉。还有一个值得注意的是,当log.2
写满后,
第三次轮转时并不会把最新的日志写到 log.1
(轮转并不同于 Round Robin 那样的循环)
轮转意味着:先把 log.2
的内容覆盖到 log.1
中,再把最新的放到 log.2
里。
如果有3个文件的话,则先把 log.2 移到 log.1, 再把 log.3 移到 log.2, 最后再把新的 app.log 移到 log.3
也就是说 计数变量最大的日志文件永远存着最新的日志信息。
按时间和容量触发
人的需求总是无限的,这个需求也蛮常见的:
要么当时间到达某个点时,要么当日志积累到某个容量时,轮转日志。俩条件达成一个就轮转。
那么这时候我们需要定义俩触发条件,每个条件在 Log4j 的配置中被称作 Triggering Policy。
按照文法要求,当我们有多个条件时,必须用一个 Policies 把它们集合在其中,像下面这样。
<RollingRandomAccessFile
filePattern="app-name.log.%d{yyyy-MM-dd-HH}">
<!-- 省略了其他属性等等 -->
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="16 KB" />
</Policies>
</RollingRandomAccessFile>
还记得那个按时间定义的 filePattern
吗,它通常是伴随着 TimeBasedTriggeringPolicy
的。
你可能会想,那要是没有 TimeBasedTriggeringPolicy
, 只要按时间定义好轮转文件名,再用上
SizeBasedTriggeringPolicy
,不也能相当按时间和容量轮转吗 ?
准确说,这样的确会在轮转日志的文件名上记录时间,但意味着日志可能并不按时间分隔开。
想象一下,如果程序 19:00 到 21:30 只断断续续生成了 15 KB 的日志,在22:00时才生成满 16KB。最后生成的文件 app-name.log.2019-08-21-22
将包含这三个小时的日志。如果生成速度更慢的话,人们将很难按小时定位。
加上 TimeBasedTriggeringPolicy
意味着告诉 Log4j 别管积累量到了没,到点了就存一下。
(是不是很像游戏里的自动存档,管你任务进展到哪了,定期存档总是稳的)
–
最后要注意的是,上面的这个配置,每个小时发生多于一次轮转时,旧日志将丢失。
因此很常见的做法是:只使用 TimeBasedTriggeringPolicy
,每小时轮转一次,而不用 SizeBasedTriggeringPolicy
,因为人们通常很清楚:自己的程序每小时也产生不了多少日志啦。
如果非要控制文件大小,那就再加上 %i
吧。
还有啥
Log4j 所提供的功能还有很多很多。这篇文章仅仅提到的轮转相关的几个设置方式。
值得探索的输出器 / Appender 还有还有许多,它们适用于不同的场景。
触发轮转也还有其他更复杂的条件,如果好奇 / 有需求的话,应该官方网站文档。
但这里,我还想再加两个值得一提的配置。
压缩日志
准确说,是压缩被轮转的日志。Log4j 是自带这个功能的,而且很容易启用。
只要给 RollingRandomAccessFile
的 filePattern
文件名添上压缩文件的后缀就可以。
# Unix / Linux 上常用 Gzip
filePattern="app.log.%i.gz"
# 也可以用 Zip
filePattern="app.log.%i.zip"
换句话说,当前正在被写入的 / 包含最新日志的文件 àpp.log
每次轮转重命名完都会被压缩。
对于节约硬盘空间,压缩日志还是很有效果的。日志作为文本文件,有很好的压缩率。我在测试时发现 100 MB 的日志文件通常可以被压缩到 7 - 8 MB 左右,接近15倍的缩小。
定期删除
还记得那个轮转策略 / Default Rollver Strategy 吗 ?
本质上,它定义了轮转发生时该如何处理旧的 / 之前轮转的日志文件。
我们之前设置的 max 属性也就是在告诉 Log4j, 轮转时看下旧日志有多少,超过 N 个了就删最旧的。
轮转时这里我们还能做许多其他事,比如 更精确定位要删的旧日志。
<DefaultRolloverStrategy>
<Delete basePath="日志的目录完整路径" maxDepth="2">
<IfFileName glob="app.log.gz.*" />
<IfLastModified age="30d" />
</Delete>
</DefaultRolloverStrategy>
只需要在策略里加上一个 Delete
设置就好啦,它的内部是 被删文件必须达到的所有条件。
这里我写了两个最常用的删除条件,一个是模糊文件名,另一个是文件上次被更新的时间(衡量新旧)。
定义模糊文件名的目的是,我们只希望删除日志文件,而不希望误删了同目录下的其他文件。
在上面的定义里,甚至通过文件后缀写明了要删除的是 压缩了的日志。
另外想说的是,IfFileName
是有两个属性 glob
和 regex
,定义其中一个就好。
后者是正则表达式,前者 glob 的语法非常相近,更常用于文件系统的匹配。
Log4j 在删文件时还是很谨慎的,必须定义 basePath 属性,只有在这个目录里的文件可能被匹配删除。
还有一个 maxDepth 表示,当 basePath 里有子目录时,最多进入多深的子目录去搜索文件。
把它设置成 1 的话,Log4j 就不会进入任何 basePath 的子目录去删除文件啦。
更多
Log4j 还有很多不同的策略,DefaultRolloverStrategy
只是默认的最简便的。
后退一步,Log4j 还有很多的功能,由不同的 Logger, Appender 和 Policy 组合提供。
如果想要了解它们,还是应该阅读官网的文档。