I've been looking into this issue I've been having a bit, but so far haven't found a single one with the same (or even a similar) problem.
The problem is not in 'how to configure the RollingFileAppender'. It is configured, it is actually rolling over. So far so good.
The context is, each day, every 15 minutes, we execute a batch, of which we write the output to two distinct log files:
- a general log file, containing all the output
- a functional log, containing only that part of the output which is relevant for the analysts.
The configuration is as follows:
log4j.rootLogger = info, rollingFile, functionalLog
log4j.appender.rollingFile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.rollingFile.File= ../logs/general_log.log
log4j.appender.rollingFile.layout=org.apache.log4j.PatternLayout
log4j.appender.rollingFile.layout.ConversionPattern=%p %d %t %c - %m%n
log4j.appender.rollingFile.DatePattern='.'yyyy-MM-dd
log4j.appender.functionalLog=org.apache.log4j.DailyRollingFileAppender
log4j.appender.functionalLog.File= ../logs/functional_log.log
log4j.appender.functionalLog.layout=org.apache.log4j.PatternLayout
log4j.appender.functionalLog.layout.ConversionPattern=%m - %d%n
log4j.appender.functionalLog.filter.1=org.apache.log4j.varia.StringMatchFilter
log4j.appender.functionalLog.filter.1.StringToMatch=FUNC-LOG -
log4j.appender.functionalLog.filter.1.AcceptOnMatch=true
log4j.appender.functionalLog.filter.2=org.apache.log4j.varia.DenyAllFilter
This configuration has worked for months. The batch executed every 15 minutes (triggered by a crontab), and each night, two rolled over files:
general_log.log.2020-05-18 function_log.log.2020-05-18
were created, containing all the loggings of that particular day. The logs were complete, we were happy.
A few days ago, we noticed we were losing logs: apparently, even though the first roll over (at midnight) would succeed, the system would roll over for a second time. Each day, the batch execution of 10.30 am would (again) trigger the (current) logs to be rolled over.
This caused the dated file of the day before, containing all the logs of that day, to be overwritten with the logs of the first ten and a half hours of the current day. Result: the logs were in the log files of the day before, and we only had about ten hours worth of logs a day, instead of 24.
During the investigation, I noticed I forgot the DatePattern on the FunctionalLog config, so I added this:
log4j.appender.functionalLog.DatePattern='.'yyyy-MM-dd
Now, I know it is possible to set the rollover at yearly, monthly, daily, hourly, each minute, ..., but for some reason, there is some execution each day (10.30 am) that makes it roll over again. There is no config in the log4j, nor in the batch, that can explain this.
There have been no changes in neither the deployed code, the log4j configuration, nor in the configuration of the server.
Has anyone encountered an issue like this before? Is there anything in the config we can do to avoid this?
