问题描述

压力测试阶段，笔者发现springboot项目日志文件的磁盘占用空间达到3GB且还在不断增加，但是笔者设置的日志文件总容量限制即totalSizeCap是1GB。问题如下：

1. totalSizeCap参数未生效，不能控制日志文件总容量。
2. logback日志文件滚动策略是新文件产生后，会对旧文件进行编号归档。笔者发现日志文件编号0-999的文件不存在了，但1000以上编号的日志文件一直在。也就是部分日志文件被删除。

环境参数说明

• Springboot 2.1
• JDK 1.8
• logback 1.2.3

logback日志策略如下所示：

1. 日志文件大小是10MB
2. 日志文件保留7天
3. info目录下的所有日志文件总磁盘占用量设置1GB

    <appender name="INFO_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在记录的日志文件的路径及文件名 -->
        <file>${log.path}/log_info.log</file>
        <!--日志文件输出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <!-- 日志记录器的滚动策略，按日期，按大小记录 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天日志归档路径以及格式 -->
            <fileNamePattern>${log.path}/info/log-info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <totalSizeCap>1GB</totalSizeCap>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天数-->
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只记录info级别的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

分析日志文件策略

1. 当前处于压测阶段，日志输出量级很大，半个小时左右就可以生成几千个文件，文件编号达到log-info-2021-12-19.2341.log。笔者首先找到了一个关于logback1.1.x版本的bug，说的是totalSizeCap是int类型时，logback不能删除totalSizeCap大于2GB左右的日志文件。这个问题的已经在logback1.2.0修复，即使用long类型声明totalSizeCap。
   
   
2. 笔者继续谷歌后发现2020年就有人报出只能删除编号是999以内的日志文件，具体信息可以参看bug。

源码解析

根据logback官网文档，SizeAndTimeBasedRollingPolicy基于时间+空间策略来管理日志文件。

Size and time based rolling policy Sometimes you may wish to archive files essentially by date but at the same time limit the size of each log file, in particular if post-processing tools impose size limits on the log files. In order to address this requirement, logback ships with SizeAndTimeBasedRollingPolicy.

1. 日志归档策略类图

2. 日志删除策略类图。

3. 父类TimeBasedRollingPolicy中最核心的方法是start()，在类SizeAndTimeBasedRollingPolicy中已经指定了对象timeBasedFileNamingAndTriggeringPolicy是SizeAndTimeBasedFNATP的实例化对象。

4. TimeBasedRollingPolicy的start()方法中，先启动实例化对象SizeAndTimeBasedFNATP的start()方法，获取到archiveRemover对象，他是负责根据时间+空间执行具体日志策略的对象。

5. 笔者找到了基于时间功能的归档日志清理类TimeBasedArchiveRemover，cleanAsynchronously()方法启动一个定时任务，异步执行文件删除操作。归档删除执行类ArhiveRemoverRunnable负责判断磁盘容量并删除文件。注意totalSizeCap在logback.xml中必须要设置为非0的正整数，否则不会执行删除归档日志的操作。

6. 父类TimeBasedArchiveRemover中定义了方法capTotalSize(Date now)，即根据磁盘容量清理日志文件。主要包括如下功能：

• 根据日志保留天数maxHistory，getEndOfNextNthPeriod计算已经超出maxHistory以外的日期
• 根据文件修改日期，降序排序。先统计最近的各文件容量和知否已经达到totalSizeCap。目的是尽可能删除日期比较久远的文件。
• getFilesInPeriod()方法后面步骤会单独介绍。
• 获取到指定文件后就删除。
  

7. 父类TimeBasedArchiveRemover执行capTotalSize(Date now)时，子类重写了getFilesInPeriod方法，因此在获取指定的文件列表时，需要使用子类SizeAndTimeBasedArchiveRemover的getFilesInPeriod方法。
   
   
8. 关于totalSizeCap未生效问题，logback也经历过几个版本的迭代。
   - logback1.2.3中是{1,3}
   - logback1.2.x中是{1,5}
   - logback master(本文写作日期20211223) 使用正则匹配所有数字\d

总结

1. 调整日志参数。
   临时方案是根据实际情况调整单个文件大小以及磁盘占用空间大小，例如单个文件调大到50MB，容量限制提高到2GB。
2. 调整日志输出策略
   在实际产线中，一般在debug级别下才需要输出entity所有信息，info级别只需要输出关键节点信息即可，不需要如此详细的日志信息。故此处修改为log.debug("xxxx")比较合理。

引用

• https://www.elietio.xyz/posts/f6b1711c.html
• http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy