David Johle created LOG4J2-117:
----------------------------------
Summary: Double-rollover occuring, loosing logs
Key: LOG4J2-117
URL: https://issues.apache.org/jira/browse/LOG4J2-117
Project: Log4j 2
Issue Type: Bug
Components: Appenders, Core
Affects Versions: 2.0-alpha2
Environment: Java 1.6.x
Tomcat 7.0.x
Reporter: David Johle
Attachments: doubleroll.xml
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, however the
recently-created file is archived which overwrites the properly archived one in
the process
(not good!)
Further hits to either JSP continue in current file, until the next day's
double-rollover
Attached is my (slightly simplified for readability and test case purposes)
config file.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
