【背景】

        前段时间在工作中发现,在nginx的自定义模块中使用log4j打印日志时,出现丢失日志&日志打印的日期混乱的问题。于是决定查查。

【现象】

配置:

        1)在log4j配置文件中设置的按天切割文件,由于有多个进程,每个进程都读同样的配置,写同样的日志文件。

        2)nginx配置12个进程

现象:

        第一天(2016-11-14):

        12个进程分别持有不同的fd,写入同一个日志文件abc.log

        第二天(2016-11-15):

        abc.log和abc.log.2016-11-14同时被写入

        进程1写入abc.log

        进程2写入abc.log.2016-11-14

        其他进程没有写日志文件

【原因】

日志切割引起的问题。

        在log4j的DailyRollingFileAppender类(继承于FileAppender)中有个rollover方法,该方法的作用是:

        在滚动备份时间间隔到的时刻,将前一时间间隔的日志备份,同时以非追加模式将新日志写到新日志文件中;

        如果备份文件不存在,则备份,同时创建新日志文件;如果存在,则先删除掉,再备份。

nginx日志 nginx日志切割日志丢失_备份文件

        所以,如果同时有A、B、C三个进程操作一个日志,

初始时:

A、B、C分别持有fd1、fd2、fd3写入文件abc.log

日志切换时:

1)进程A

  • abc -> abc.2016-01-01
  • 使用fd4写入abc.log

2)进程B

  • 删除abc.2016-01-01(前一天全量日志)
  • abc -> abc.2016-01-01(此时进程A使用fd4向abc.2016-01-01写入)
  • 使用fd5写入abc.log

3)进程C

  • 删除abc.2016-01-01(进程A正在写入的日志)
  • abc -> abc.2016-01-01(此时进程B使用fd5向abc.2016-01-01写入)
  • 使用fd6写入abc.log

结果:

1)第一天的日志被删掉

2)abc.2016-01-01记录的是进程B在2012-01-02写入的日志;abc.2016-01-02记录的是进程B在2012-01-03写入的日志

3)abc记录的是进程C当前写入的日志

【解决】

1)不同进程根据进程编号使用不同的配置文件,写日志到不同的日志文件

2)修改log4j的rollover方法的实现

定义TaskDailyRollingFileAppender类,该类继承FileAppender,切割规则:

如果备份文件存在,则直接以追加的方式将日志写入abc.log

nginx日志 nginx日志切割日志丢失_nginx日志_02

【小结】

        在多进程的服务中使用log4j会有日志打印问题,漏日志和日志时间错乱;

        可以通过为每个进程指定不同的日志文件名解决,也可以修改log4j的日志切割方式解决。