记录一次线上logback日志打印中断问题:

背景:线上生产环境正在运行的一个微服务,运行一段时间之后,日志log突然消失。打印不出来最新的日志。系统正常运行,无异常。微服务也不收影响,无任何异常,针对这一问题,展开排查


问题描述:

微服务正常运行,各项指标均正常,请求无异常,日志监控平台采集不到最新日志。linux服务器logs指定日志目录下为空,历史log记录也没有。

经过询问开发和运维同事,得知,我们自己有一套日志采集系统,服务器集成的ELK日志采集,业务服务系统,会把日志通过logback打印到外挂磁盘 /data/logs/app/xxx/目录下。 elk会把 /data/logs/app/xxx/目录下日志采集到es数据库,然后通过kibana展示出来。然后会定期删除前几天的/data/logs/app/xxx/的日志文件:
在这里插入图片描述


原因分析:

1.首先排查liunx服务器是否有问题:因为目前/data/logs/目录下完全为空,导致没法排查。追问运维以及相关人员。说elk采集完日志,会定期删掉前几天的文件,当前天的日志不会删除。听起来应该不是服务器问题。

2.排查代码:首先想到的是,本业务系统,是否有删除文件的动作。排查io写入和读取等操作。并没有发现有删除操作。

3.由于是docker容器化部署,不存在一个docker容器存在多个服务的问题。不会是其它业务系统删除

4.检查log日志打印方式,检查配置文件,发现是logback方式。简单看一遍,也没有发现问题,如下

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- 文件配置 -->
    <appender name="xxxAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--日志文件输出的文件名 -->
            <FileNamePattern>/data/logs/xxx/app/xxx.%d{yyyy-MM-dd}.log
            </FileNamePattern>
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <!--日志文件最大的大小 -->
        <triggeringPolicy
                class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>100MB</MaxFileSize>
        </triggeringPolicy>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS,GMT+8} %p %m%n</pattern>
            <charset class="java.nio.charset.Charset">UTF-8</charset>
        </encoder>
    </appender>
    <root>
        <level value="INFO"/>
        <appender-ref ref="xxxAppender"/>
    </root>
</configuration>

5.上面的配置,是通用的配置。好多公司都是这样的。也没有发现特别异常的点。最后只能去logback官网看一下是否有特别说明。

6.通过SizeBasedTriggeringPolicy类TimeBasedRollingPolicy类配置参数了解,
如果设置了SizeBasedTriggeringPolicy类,会导致先判断大小阈值,大小阈值满足了,才会滚动TimeBasedRollingPolicy。

7.通过以上步骤,在结合之前运维给的elk的反馈。大致可以猜测到一个问题点:
SizeBasedTriggeringPolicy阈值设置过大,导致会出现不生成当天新文件. 因为只有满足阈值,才会生产滚动,另外运维日志采集系统采集完日志后,会定期删掉过去历史天数log.
如果现在服务的日志打印少,导致不生成今天新文件,今天的日志还打印在昨天明天的日志文件里面,这个时候elk把昨天的日志文件删除,导致把正在打印的logback程序写入失败。造成服务写入log日志失败,catch会close掉io数据流。从而中断打印。以后也不打印了。造成elk采集不到。还把过去日期文件删除。/data/logs目录下为空

解决方案:

优化logback.xml。
采用SizeAndTimeBasedRollingPolicy类。此类不会先去判断阈值,会优先按照日期滚动,如果满足阈值,也会滚动生成新的日志文件

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
 
    <!-- xxx文件配置 -->
    <appender name="xxxAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!--日志文件输出的文件名-->
            <FileNamePattern>/data/logs/xxx.%d{yyyy-MM-dd}.%i.log</FileNamePattern>
            <MaxFileSize>100MB</MaxFileSize>
            <!--日志文件保留天数-->
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS,GMT+8} %p %m%n</pattern>
            <charset class="java.nio.charset.Charset">UTF-8</charset>
        </encoder>
    </appender>
 
    <root>
        <level value="INFO"/>
        <appender-ref ref="xxxAppender"/>
    </root>
</configuration>

结束

Logo

权威|前沿|技术|干货|国内首个API全生命周期开发者社区

更多推荐