一、背景
后台有很多任务，每个任务都是一个main函数（JVM或进程），但是所有的任务都往同一份日志文件中输出日志。任务上线当天，日志没有问题，当第二天后，日志输出混乱
二、代码分析
我们来分析下，在 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进程先进行滚动备份，B进程后进行滚动备份
1、对于A进程：
a. 先将data.log备份(renameTo())为data.log.2017.11.30，然后创建data.log文件，并将日志写在data.log中；
b. 此时A进程持有data.log的文件句柄；而B进程仍然持有data.log.2017.11.30的文件句柄(尽管被重命名，但句柄不变)；
2、对于B进程：
发现以data.log.2017.11.30为文件名的文件已经存在，则将其删除(前一时间段的所有日志全没了)，并将以data.log为文件名的文件重命名为data.log.2017.11.30，然后创建data.log文件；
3、此时A进程持有data.log.2017.11.30的文件句柄(被B进程重命名过)），而B进程持有最新创建的data.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属性区分日志文件
如果是任务，根据启动参数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结尾，实现日志与任务一对一的关系。
