[LOG4J2-1548][CronTriggeringPolicy] ConfigurationScheduler schedules the task infinitely after first fire. Heads-up: The new test has a TODO noting that the test uses Thread.sleep() all over the place; it takes about a minute to run. Expect a 1-minute slower build until a better test is in place. Note that the part of the patch related to ResolverUtil was not applied.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/33aaf3d5 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/33aaf3d5 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/33aaf3d5 Branch: refs/heads/LOG4J2-1010&LOG4J2-1447-injectable-contextdata&better-datastructure Commit: 33aaf3d52503a3c5781a30424994ad1b5907d59e Parents: 8b40c1f Author: Gary Gregory <ggreg...@apache.org> Authored: Wed Aug 24 08:51:39 2016 -0700 Committer: Gary Gregory <ggreg...@apache.org> Committed: Wed Aug 24 08:51:39 2016 -0700 ---------------------------------------------------------------------- .../core/config/ConfigurationScheduler.java | 2 +- .../RollingAppenderCronOnceADayTest.java | 128 +++++++++++++++++++ .../resources/log4j-rolling-cron-once-a-day.xml | 47 +++++++ .../src/test/resources/log4j-rolling-cron.xml | 2 +- .../src/test/resources/log4j-rolling-cron2.xml | 2 +- src/changes/changes.xml | 3 + 6 files changed, 181 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java index 744ed24..e6291f9 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java @@ -182,7 +182,7 @@ public class ConfigurationScheduler extends AbstractLifeCycle { } catch(final Throwable ex) { LOGGER.error("Error running command", ex); } finally { - Date fireDate = cronExpression.getNextInvalidTimeAfter(new Date()); + Date fireDate = cronExpression.getNextValidTimeAfter(new Date()); final ScheduledFuture<?> future = schedule(this, nextFireInterval(fireDate), TimeUnit.MILLISECONDS); scheduledFuture.reset(future, fireDate); } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderCronOnceADayTest.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderCronOnceADayTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderCronOnceADayTest.java new file mode 100644 index 0000000..2e091c4 --- /dev/null +++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderCronOnceADayTest.java @@ -0,0 +1,128 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender.rolling; + +import static org.apache.logging.log4j.hamcrest.Descriptors.that; +import static org.apache.logging.log4j.hamcrest.FileMatchers.hasName; +import static org.hamcrest.Matchers.endsWith; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertTrue; + +import java.io.File; +import java.nio.file.FileSystems; +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.Calendar; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.appender.RollingFileAppender; +import org.apache.logging.log4j.core.util.CronExpression; +import org.apache.logging.log4j.junit.LoggerContextRule; +import org.apache.logging.log4j.status.StatusLogger; +import org.hamcrest.Matcher; +import org.junit.BeforeClass; +import org.junit.Rule; +import org.junit.Test; +import org.junit.rules.RuleChain; + +/** + * This test currently takes about a minute to run. + */ +public class RollingAppenderCronOnceADayTest { + + private static final String UTF_8 = "UTF-8"; + private static final String CONFIG = "log4j-rolling-cron-once-a-day.xml"; + private static final String CONFIG_TARGET = "log4j-rolling-cron-once-a-day-target.xml"; + private static final String TARGET = "target"; + private static final String DIR = TARGET + "/rolling-cron-once-a-day"; + private static final String FILE = DIR + "/rollingtest.log"; + private static final String TARGET_TEST_CLASSES = TARGET + "/test-classes"; + + private static String cronExpression; + private static long remainingTime; + + @BeforeClass + public static void beforeClass() throws Exception { + final Path src = FileSystems.getDefault().getPath(TARGET_TEST_CLASSES, CONFIG); + String content = new String(Files.readAllBytes(src), UTF_8); + Calendar cal = Calendar.getInstance(); + cal.add(Calendar.SECOND, 45); + remainingTime = cal.getTimeInMillis() - System.currentTimeMillis(); + cronExpression = String.format("%d %d %d * * ?", + cal.get(Calendar.SECOND), + cal.get(Calendar.MINUTE), + cal.get(Calendar.HOUR_OF_DAY)); + content = content.replace("@CRON_EXPR@", cronExpression); + Files.write(FileSystems.getDefault() + .getPath(TARGET_TEST_CLASSES, CONFIG_TARGET), content.getBytes(UTF_8)); + StatusLogger.getLogger().debug("Cron expression will be " + cronExpression + " in " + remainingTime + "ms"); + } + + private final LoggerContextRule loggerContextRule = new LoggerContextRule(CONFIG_TARGET); + + @Rule + public RuleChain chain = loggerContextRule.withCleanFoldersRule(true, false, 1, DIR); + + @Test + public void testAppender() throws Exception { + // TODO Is there a better way to test than putting the thread to sleep all over the place? + final Logger logger = loggerContextRule.getLogger(); + File file = new File(FILE); + assertTrue("Log file does not exist", file.exists()); + logger.debug("This is test message number 1, waiting for rolling"); + + final RollingFileAppender app = (RollingFileAppender) loggerContextRule.getContext().getConfiguration().getAppender("RollingFile"); + final TriggeringPolicy policy = app.getManager().getTriggeringPolicy(); + assertNotNull("No triggering policy", policy); + assertTrue("Incorrect policy type", policy instanceof CronTriggeringPolicy); + final CronExpression expression = ((CronTriggeringPolicy) policy).getCronExpression(); + assertEquals("Incorrect cron expresion", cronExpression, expression.getCronExpression()); + logger.debug("Cron expression will be {}", expression.getCronExpression()); + + // force a reconfiguration + for (int i = 1; i <= 20; ++i) { + logger.debug("Adding first event {}", i); + } + + Thread.sleep(remainingTime); + final File dir = new File(DIR); + assertTrue("Directory not created", dir.exists() && dir.listFiles().length > 0); + + for (int i = 1; i < 20; i++) { + logger.debug("Adding again event {}", i); + } + Thread.sleep(1000); + for (int i = 1; i < 10; i++) { + logger.debug("Adding some more event {}", i); + Thread.sleep(1000); + } + final Matcher<File> hasGzippedFile = hasName(that(endsWith(".gz"))); + int count = 0; + final File[] files = dir.listFiles(); + for (File generatedFile : files) { + if (hasGzippedFile.matches(generatedFile)) { + count++; + } + } + + assertNotEquals("No compressed files found", 0, count); + assertEquals("Multiple files found" , 1, count); + } + +} http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/log4j-core/src/test/resources/log4j-rolling-cron-once-a-day.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/log4j-rolling-cron-once-a-day.xml b/log4j-core/src/test/resources/log4j-rolling-cron-once-a-day.xml new file mode 100644 index 0000000..9d71fc9 --- /dev/null +++ b/log4j-core/src/test/resources/log4j-rolling-cron-once-a-day.xml @@ -0,0 +1,47 @@ +<?xml version="1.0" encoding="UTF-8"?> +<!-- + Licensed to the Apache Software Foundation (ASF) under one or more + contributor license agreements. See the NOTICE file distributed with + this work for additional information regarding copyright ownership. + The ASF licenses this file to You under the Apache License, Version 2.0 + (the "License"); you may not use this file except in compliance with + the License. You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. + +--> +<Configuration status="ERROR" name="RollingCronTestOnceADay"> + <Properties> + <Property name="filename">target/rolling-cron-once-a-day/rollingtest.log</Property> + </Properties> + + <Appenders> + <Console name="STDOUT" target="SYSTEM_OUT"> + <PatternLayout pattern="%p %C{1.} [%t] %m%n"/> + </Console> + <RollingFile name="RollingFile" + fileName="${filename}" + filePattern="target/rolling-cron-once-a-day/rollingtest-%d{yyyyMMdd}_%d{HHmmss}-%i.log.gz" + immediateFlush="true"> + <PatternLayout pattern="%d %p %C{1.} [%t] %m%n" /> + <CronTriggeringPolicy schedule="@CRON_EXPR@"/> + </RollingFile> + </Appenders> + + <Loggers> + <Logger name="org.apache.logging.log4j.core.appender.rolling" level="DEBUG" additivity="false"> + <AppenderRef ref="RollingFile"/> + </Logger> + + <Root level="ERROR"> + <AppenderRef ref="STDOUT"/> + </Root> + </Loggers> + +</Configuration> \ No newline at end of file http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/log4j-core/src/test/resources/log4j-rolling-cron.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/log4j-rolling-cron.xml b/log4j-core/src/test/resources/log4j-rolling-cron.xml index 9579804..be6fa70 100644 --- a/log4j-core/src/test/resources/log4j-rolling-cron.xml +++ b/log4j-core/src/test/resources/log4j-rolling-cron.xml @@ -44,7 +44,7 @@ <Loggers> <Logger name="org.apache.logging.log4j.core.appender.rolling" level="debug" additivity="false"> <AppenderRef ref="RollingFile"/> - </Logger>> + </Logger> <Root level="error"> <AppenderRef ref="STDOUT"/> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/log4j-core/src/test/resources/log4j-rolling-cron2.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/log4j-rolling-cron2.xml b/log4j-core/src/test/resources/log4j-rolling-cron2.xml index a6a17ed..9110f50 100644 --- a/log4j-core/src/test/resources/log4j-rolling-cron2.xml +++ b/log4j-core/src/test/resources/log4j-rolling-cron2.xml @@ -44,7 +44,7 @@ <Loggers> <Logger name="org.apache.logging.log4j.core.appender.rolling" level="debug" additivity="false"> <AppenderRef ref="RollingFile"/> - </Logger>> + </Logger> <Root level="error"> <AppenderRef ref="STDOUT"/> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/33aaf3d5/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 776da03..dbc3310 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -24,6 +24,9 @@ </properties> <body> <release version="2.7" date="2016-MM-DD" description="GA Release 2.7"> + <action issue="LOG4J2-1548" dev="ggregory" type="fix" due-to="Gary Gregory"> + [CronTriggeringPolicy] ConfigurationScheduler schedules the task infinitely after first fire. + </action> <action issue="LOG4J2-1506" dev="ggregory" type="fix" due-to="Johannes Schleger"> Unregister JMX ignores log4j2.disable.jmx property. </action>
