读书人

多进程log4j日志丢失有关问题分析

发布时间: 2012-10-25 10:58:58 作者: rapoo

多进程log4j日志丢失问题分析

一、背景:后台有很多任务,每个任务都是一个main函数(JVM或进程),但是所有的任务都加载同一个log4j.xml文件,即往同一份文件中输出日志。

二、原因追踪

在?log4j?的?DailyRollingFileAppender?类中:

void rollOver() throws IOException {    /* Compute filename, but only if datePattern is specified */    if (datePattern == null) {      errorHandler.error("Missing DatePattern option in rollOver().");      return;    }    String datedFilename = fileName+sdf.format(now);    // It is too early to roll over because we are still within the    // bounds of the current interval. Rollover will occur once the    // next interval is reached.    if (scheduledFilename.equals(datedFilename)) {      return;    }    // close current file, and rename it to datedFilename    this.closeFile();    File target  = new File(scheduledFilename);    if (target.exists()) {      target.delete();    }    File file = new File(fileName);    boolean result = file.renameTo(target);    if(result) {      LogLog.debug(fileName +" -> "+ scheduledFilename);    } else {      LogLog.error("Failed to rename ["+fileName+"] to ["+scheduledFilename+"].");    }    try {      // This will also close the file. This is OK since multiple      // close operations are safe.      this.setFile(fileName, false, this.bufferedIO, this.bufferSize);    }    catch(IOException e) {      errorHandler.error("setFile("+fileName+", false) call failed.");    }    scheduledFilename = datedFilename;}
该方法的作用是:在滚动备份时间间隔到的时刻,将前一时间间隔的日志备份,同时以非追加模式将新日志打到新日志文件中;

中间部分代码意思是:如果备份文件不存在,则备份,同时创建新日志文件;如果存在,则先删除掉,再备份;

?

好,问题在这个时刻就出现了:(假设A进程先进行滚动备份)

1、对于A进程:
a. 先将project.log备份(renameTo())为project.log.2009.08.18,然后创建project.log文件,并将日志写在project.log中;
b. 此时A进程持有project.log的文件句柄;而B进程仍然持有project.log.2009.08.18的文件句柄(尽管被重命名,但句柄不变);

2、对于B进程:发现以project.log.2009.08.18为文件名的文件已经存在,则将其删除(前一时间段的所有日志全没了),并将以project.log为文件名的文件重命名为project.log.2009.08.18,然后创建project.log文件;

3、此时A进程持有project.log.2009.08.18的文件句柄(被B进程重命名过的),而B进程持有最新创建的project.log;

4、结果导致:前一时间段日志丢失,A、B进程在不同的文件里打日志;

三、解决方案

1、改变?rollOver()?方法的实现方式:定义?TaskDailyRollingFileAppender?类,该类继承至?FileAppender?,它与?DailyRollingFileAppender?的主要区别在于以下方法:

void rollOver() throws IOException {    /* Compute filename, but only if datePattern is specified */    if (datePattern == null) {      errorHandler.error("Missing DatePattern option in rollOver().");      return;    }    String datedFilename = fileName+sdf.format(now);    // It is too early to roll over because we are still within the    // bounds of the current interval. Rollover will occur once the    // next interval is reached.    if (scheduledFilename.equals(datedFilename)) {      return;    }    // close current file, and rename it to datedFilename    this.closeFile();    File target  = new File(scheduledFilename);    if (!target.exists()) {        File file = new File(fileName);        boolean result = file.renameTo(target);        if (result) {            LogLog.debug(fileName + " -> " + scheduledFilename);        } else {            LogLog.error("Failed to rename [" + fileName + "] to [" + scheduledFilename + "].");        }    }    try {        // This will also close the file. This is OK since multiple        // close operations are safe.        this.setFile(fileName, true, this.bufferedIO, this.bufferSize);    }    catch(IOException e) {      errorHandler.error("setFile("+fileName+", false) call failed.");    }    scheduledFilename = datedFilename;}
改进后的?rollOver()?方法主要作用是:A进程先将日志重命名,然后创建新日志文件,B进程发现已经存在,则直接以追加模式切换到新的日志文件上去;

?

2、如果是任务,根据启动参数taskName?属性区分日志文件:

a. 目前所有后台任务在启动脚本里都加上了?-DtaskName?属性;
b. 定义?TaskDailyRollingFileAppender?类,该类继承?DailyRollingFileAppender,并覆盖其?setFile(String file)?方法:

public void setFile(String file) {    String taskName = System.getProperty("taskName");    if (!StringUtil.isEmpty(taskName)) {        file = file + "." + taskName;    }    super.setFile(file);}
?c.?这样实现后,对于不同的任务,日志文件名会以.taskName结尾,对于没有指定?taskName?的任务,不受影响; 1 楼 weilJava 2011-05-25 昨天被问到了多进程读写文件的问题
一点思路都没 2 楼 diecui1202 2011-05-25 weilJava 写道昨天被问到了多进程读写文件的问题
一点思路都没
这个问题确实比较头疼啊~能否借助文件来实现同步?

读书人网 >编程

热点推荐