Details
Description
I've noticed an interesting double-rollover happening, which I think is related to having two references to the same appender. It seems to keep track of the triggering events for each one separately or something.
Backstory:
The general setup in this case is that I have some JSP based websites running under Tomcat. I also have a library of utility code that they all share. Some of the utilities are used during the startup phase, and as a result the logging is a disparate mess due to different code being loaded by different classloaders and so on.
My eventual solution to all this, which works well, is to have all Loggers managed under a single centralized configuration and under the common classloader, including Tomcat's logging itself. I then use a servlet filter on each webapp to set a value in the MDC/ThreadContext, and a Routing logger to send the webapp-generated log events (be it from a JSP or a shared utility library) to appropriate location. Anything else is just dumped in the central log file.
Also, the JSP code still has several legacy components which are using old System.out.println() style calls that are still being replaced with proper logging calls via log4j. In the meantime, I still want to capture those events inline, so I use Tomcat's swallowOutput feature to have it intercept them.
Because the System.out calls are handled by the container directly, they don't carry the MDC/ThreadContext key. As a result, I have to manually route them to the appropriate appender. Fortunately Tomcat assigns a logger name that is webapp specific, so I have something to identify them by.
Behavior:
Since I'm doing daily rolling, set system time to 11:59 PM
Start server up
Hit a test JSP which performs a log4j call, see entry in the webapp specific log file
Hit another test JSP which performs a System.out call, see entry in the same webapp specific log file
Wait for a minute so that system time is now in next day
Hit one of the test JSP files again
See logfile rollover happen, old file archived, and entry in the newly created file
Hit that same test JSP again, entry just below previous
(all good so far)
Hit the other test JSP
See logfile rollover happen again (!!), entry in the newly created file, and the recently-created file is archived which overwrites the properly archived one in the process (!!)
(I've lost a whole day of logs, this is very bad)
Further hits to either JSP continue in current file as they should, until the next day's double-rollover happens
Attached is my (slightly simplified for readability and test case purposes) config file.