[
https://issues.apache.org/jira/browse/LOG4J2-531?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13895828#comment-13895828
]
Remko Popma commented on LOG4J2-531:
------------------------------------
Geoff, just a preliminary update (still investigating):
because {{DefaultRolloverStrategy}} is configured with {{max="999999"}}, the
rollover logic will allow for up to 1 million files with the same timestamp
(but a different %i index if the rollover was triggered by the size threshold).
Within the same time window, the rollover logic will then ensure that no more
than {{max}} files are created, and if the max has been reached, then the logic
will remove the oldest file and rename all other indexed files to make room for
the new one.
(See
[DefaultRolloverStrategy|http://logging.apache.org/log4j/2.x/manual/appenders.html#DefaultRolloverStrategy].)
Why is this relevant? The logic above is implemented as a loop that will count
down from 999999 to 1 (almost 1 million times), and call {{if (new
File(format(pattern, i)).exists()) ...}} in order to check if such a file
exists and needs to be renamed.
I suspect that accessing the disk so often will take significant time, and that
the first rollover action is not complete yet when other threads have logged
enough to trigger the next rollover, and that these overlapping rollover
actions cause the problem you are seeing.
If I am correct, the problem can be worked around by creating a smaller time
window, configuring a larger {{size}} for {{SizeBasedTriggeringPolicy}} so you
can configure a smaller value for {{max}} in {{DefaultRolloverStrategy}}.
I will continue investigating and update later.
> Rolled log files overwritten by RollingFile appender with composite time and
> size based policies
> ------------------------------------------------------------------------------------------------
>
> Key: LOG4J2-531
> URL: https://issues.apache.org/jira/browse/LOG4J2-531
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0-beta9
> Environment: Ubuntu 12.04 and 13.04, java version "1.7.0_51"
> Reporter: Geoff Ballinger
>
> We have a system which generates high volume logs which are required to be
> preserved for audit purposes, and have been having problems with files being
> unexpectedly overwritten.
> We are using a RollingFile appender with day granularity, time based and size
> based triggering policies, and a rollover strategy with a suitably large max
> value.
> I have created a simple test case with minute granularity to quickly
> illustrate the problem, which is v. similar to the example given in the
> documentation:
> {noformat}
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> public class LogTest
> {
> private static final Logger logger = LogManager.getLogger("TestLogger");
> public static void main(String[] args) throws Exception
> {
> for (long i=0; ; i+=1) {
> logger.debug("Sequence: " + i);
> Thread.sleep(250);
> }
> }
> }
> {noformat}
> ... with a config of:
> {noformat}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration>
> <Appenders>
> <RollingFile name="Test" fileName="logs/test.log"
> filePattern="logs/test/$${date:yyyyMMddHHmm}/TEST-%d{yyyyMMddHHmm}-%i.log.gz">
> <PatternLayout pattern="%d %p (%t) [%c] - %m%n"/>
> <Policies>
> <TimeBasedTriggeringPolicy />
> <SizeBasedTriggeringPolicy size="1 KB"/>
> </Policies>
> <DefaultRolloverStrategy max="999999"/>
> </RollingFile>
> </Appenders>
> <Loggers>
> <Root level="debug">
> <AppenderRef ref="Test"/>
> </Root>
> </Loggers>
> </Configuration>
> {noformat}
> If this is run as is many of the rollover logfiles have other files written
> over them and are lost, as can clearly be seen by the gaps in the remaining
> sequence numbers, and the order the sequence numbers appear in the resulting
> files.
> If the time based policy is removed from the config and it is re-run then all
> sequence numbers are correctly stored and in the expected order., Without the
> time based trigger some are carried over into the folder for the next period
> which is not ideal, though is what we are using at present to avoid data loss.
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
