[
https://issues.apache.org/jira/browse/LOG4J2-535?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ralph Goers reassigned LOG4J2-535:
----------------------------------
Assignee: Ralph Goers
> Rolled log files end up in the wrong directory
> ----------------------------------------------
>
> Key: LOG4J2-535
> URL: https://issues.apache.org/jira/browse/LOG4J2-535
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0-rc1
> Environment: Ubuntu 12.04 and 13.04, java version "1.7.0_51"
> Reporter: Remko Popma
> Assignee: Ralph Goers
>
> Follow-up for issue LOG4J2-531: the main issue (rolled over archives were
> overwritten) was resolved but the solution brought to light another issue
> that is tracked here:
> The distribution of the log files into the folders is odd and it feels like
> there might be a flaw in the timestamp logic in there somewhere still.
> Test program to reproduce the issue:
> {code}
> 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);
> }
> }
> }
> {code}
> Sample configuration for LOG4J2-531:
> {code}
> <?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>
> {code}
> I kicked off the test run at {{14:29:11}} using my example setup from the
> first post above more or less as is - but with a more sensible {{max=99}}.
> The initial folder created was {{201402101429}} and contained 27 numbered
> files prefixed {{TEST-201402101429-}}. Numbers 1-12 contained 16 log lines
> each with timestamps {{14:29:11,667}} to {{14:29:59,649}}, number 13 a single
> log line with timestamp {{14:29:59,899}}, and numbers 14-27 again contain 16
> lines each with timestamps {{14:30:00,164}} to {{14:30:56,155}}.
> The second folder created was {{201402101430}} and contained 15 numbered
> files. The first file contained 15 log lines with timestamps {{14:30:56,405}}
> to {{14:30:59,919}}. The subsequent files contained 16 log lines each with
> timestamps {{14:31:00,170}} to {{14:31:56,123}}.
> The third folder created was {{201402101431}}. The first file contained 15
> log lines with timestamps {{14:31:56,373}} to {{14:31:59,886}}. The
> subsequent files contained 16 log lines each with timestamps from
> {{14:32:00,136}} onwards.
> So in summary after the first minute the majority of log lines from minute X
> end up in the folder for minute X-1. The exception are the last file of lines
> which end up in the correct folder.
> ----
> This happens with longer rollover periods as well:
> ----
> Sample configuration based on that for LOG4J2-531, adjusted to roll every
> hour and every 64kb (i.e. expect similar number of files per folder):
> {code:xml}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration>
> <Appenders>
> <RollingFile name="Test" fileName="logs/test.log"
> filePattern="logs/test/$${date:yyyyMMddHH}/TEST-%d{yyyyMMddHH}-%i.log.gz">
> <PatternLayout pattern="%d %p (%t) [%c] - %m%n"/>
> <Policies>
> <TimeBasedTriggeringPolicy />
> <SizeBasedTriggeringPolicy size="64 KB"/>
> </Policies>
> <DefaultRolloverStrategy max="99"/>
> </RollingFile>
> </Appenders>
> <Loggers>
> <Root level="debug">
> <AppenderRef ref="Test"/>
> </Root>
> </Loggers>
> </Configuration>
> {code}
> Running this overnight gave a similar pattern, e.g. the folder for
> {{2014021100}} contains one file with timestamps {{00:59:42,836}} to
> {{00:59:59,851}}, and then 15 others covering timestamps {{01:00:00,101}} to
> {{01:59:24,196}}. Only the last file's worth for each hour (the one rotated
> based on time) is in the correct folder, and the rest (rotated based on size)
> are in the previous hour's folder.
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
