- logback-dev - mailman3.qos.ch

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-32-g1d85c61
by git-noreply＠pixie.qos.ch 26 Apr '12

26 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via 1d85c612f3b275b0afeb90d9c9b038ef4e1f5c8c (commit) from aa37a6acaa0acdd3efb535177deca02c7b0772d7 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=1d85c612f3b275b0afeb90d9… http://github.com/ceki/logback/commit/1d85c612f3b275b0afeb90d9c9b038ef4e1f5… commit 1d85c612f3b275b0afeb90d9c9b038ef4e1f5c8c Author: Ceki Gulcu <ceki(a)qos.ch> Date: Thu Apr 26 14:34:10 2012 +0200 delete superflous import diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index 88aa742..10ad035 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -32,7 +32,6 @@ import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.joran.JoranConfigurator; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.spi.FilterReply; -import scala.xml.factory.LoggedNodeFactory; import static ch.qos.logback.core.CoreConstants.MILLIS_IN_ONE_SECOND; ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 1 - 1 files changed, 0 insertions(+), 1 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-31-gaa37a6a
by git-noreply＠pixie.qos.ch 26 Apr '12

26 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via aa37a6acaa0acdd3efb535177deca02c7b0772d7 (commit) from 369b71c9c28d38dd45af49925d88d4853fb6679a (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=aa37a6acaa0acdd3efb53517… http://github.com/ceki/logback/commit/aa37a6acaa0acdd3efb535177deca02c7b077… commit aa37a6acaa0acdd3efb535177deca02c7b0772d7 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Thu Apr 26 14:30:42 2012 +0200 minor edits diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index 08869c3..88aa742 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -32,6 +32,7 @@ import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.joran.JoranConfigurator; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.spi.FilterReply; +import scala.xml.factory.LoggedNodeFactory; import static ch.qos.logback.core.CoreConstants.MILLIS_IN_ONE_SECOND; @@ -88,7 +89,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { private long invocationCounter = 0; private volatile long mask = 0xF; - private long lastMaskCheck = System.currentTimeMillis(); + private volatile long lastMaskCheck = System.currentTimeMillis(); @Override @@ -122,17 +123,26 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return FilterReply.NEUTRAL; } - // for CPU intensive applications with 200 or more threads MASK values in the order of 0xFFFF is appropriate + // experiments indicate that even for CPU intensive applications with 200 or more threads MASK + // values in the order of 0xFFFF is appropriate private static final int MAX_MASK = 0xFFFF; - // update the mask so as to execute change detection code about once every 1 to 8 seconds. + + // if less than MASK_INCREASE_THRESHOLD milliseconds elapse between invocations of updateMaskIfNecessary() method, + // then the mask should be increased + private static final long MASK_INCREASE_THRESHOLD = 100; + + // if more than MASK_DECREASE_THRESHOLD milliseconds elapse between invocations of updateMaskIfNecessary() method, + // then the mask should be decreased + private static final long MASK_DECREASE_THRESHOLD = MASK_INCREASE_THRESHOLD*8; + + // update the mask so as to execute change detection code about once every 100 to 8000 milliseconds. private void updateMaskIfNecessary(long now) { - // if less than 1s elapsed since last maskUpdate double the mask size and add 1 - final long timeElapsedSinceLastCheck = now - lastMaskCheck; + final long timeElapsedSinceLastMaskUpdateCheck = now - lastMaskCheck; lastMaskCheck = now; - if (timeElapsedSinceLastCheck < MILLIS_IN_ONE_SECOND && (mask < MAX_MASK)) { + if (timeElapsedSinceLastMaskUpdateCheck < MASK_INCREASE_THRESHOLD && (mask < MAX_MASK)) { mask = (mask << 1) | 1; - } else if (timeElapsedSinceLastCheck > 8*MILLIS_IN_ONE_SECOND) { + } else if (timeElapsedSinceLastMaskUpdateCheck > MASK_DECREASE_THRESHOLD) { mask = mask >>> 2; } } diff --git a/logback-classic/src/test/input/turbo/inclusion/topByResource.xml b/logback-classic/src/test/input/turbo/inclusion/topByResource.xml index 82f5590..2037953 100644 --- a/logback-classic/src/test/input/turbo/inclusion/topByResource.xml +++ b/logback-classic/src/test/input/turbo/inclusion/topByResource.xml @@ -2,7 +2,7 @@ <!DOCTYPE x> -<configuration scan="true" scanPeriod="50 millisecond"> +<configuration scan="true" scanPeriod="50 milliseconds"> <include resource="asResource/inner1.xml"/> </configuration> diff --git a/logback-classic/src/test/input/turbo/inclusion/topLevel0.xml b/logback-classic/src/test/input/turbo/inclusion/topLevel0.xml index 48ac9f7..aacf72a 100644 --- a/logback-classic/src/test/input/turbo/inclusion/topLevel0.xml +++ b/logback-classic/src/test/input/turbo/inclusion/topLevel0.xml @@ -1,7 +1,7 @@ <?xml version="1.0" encoding="UTF-8" ?> <!DOCTYPE configuration> -<configuration scan="true" scanPeriod="50 millisecond"> +<configuration scan="true" scanPeriod="50 milliseconds"> <include file="src/test/input/turbo/inclusion/inner0.xml"/> diff --git a/logback-classic/src/test/input/turbo/scan_perf.xml b/logback-classic/src/test/input/turbo/scan_perf.xml index d652491..0e87a65 100644 --- a/logback-classic/src/test/input/turbo/scan_perf.xml +++ b/logback-classic/src/test/input/turbo/scan_perf.xml @@ -1,7 +1,7 @@ <?xml version="1.0" encoding="UTF-8" ?> <!DOCTYPE configuration> -<configuration scan="true" scanPeriod="50 millisecond"> +<configuration debug="true" scan="true" scanPeriod="30 seconds"> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <File>target/test-output/testFile.log</File> diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java b/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java index 602bb4a..351efa2 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java @@ -40,7 +40,7 @@ public class LoggingRunnable extends RunnableWithCounterAndDone { try { Thread.sleep(1); } catch (InterruptedException e) { - e.printStackTrace(); //To change body of catch statement use File | Settings | File Templates. + e.printStackTrace(); } } } diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java index d451b1b..7c7a810 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java @@ -73,18 +73,11 @@ public class ReconfigureOnChangeTest { final static String INCLUSION_SCAN_TOPLEVEL0_AS_STR = ClassicTestConstants.INPUT_PREFIX + "turbo/inclusion/topLevel0.xml"; - final static String INCLUSION_SCAN_TOPLEVEL2_AS_STR = ClassicTestConstants.INPUT_PREFIX - + "turbo/inclusion/topLevel2.xml"; - final static String INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR = ClassicTestConstants.INPUT_PREFIX + "turbo/inclusion/topByResource.xml"; - final static String INCLUSION_SCAN_INNER0_AS_STR = ClassicTestConstants.INPUT_PREFIX + "turbo/inclusion/inner0.xml"; - final static String INCLUSION_SCAN_INNER2_AS_STR = ClassicTestConstants.INPUT_PREFIX - + "turbo/inclusion/inner2.xml"; - final static String INCLUSION_SCAN_INNER1_AS_STR = "target/test-classes/asResource/inner1.xml"; diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java index dd93afb..ef2a210 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java @@ -47,7 +47,7 @@ public class ReconfigurePerf { int sleepBetweenUpdates = DEFAULT_SLEEP_BETWEEN_UPDATES; - static int numberOfCycles = 150; + static int numberOfCycles = 100; static int totalTestDuration; LoggerContext loggerContext = new LoggerContext(); diff --git a/logback-site/src/site/pages/manual/configuration.html b/logback-site/src/site/pages/manual/configuration.html index df1679a..2c81abe 100644 --- a/logback-site/src/site/pages/manual/configuration.html +++ b/logback-site/src/site/pages/manual/configuration.html @@ -448,10 +448,10 @@ public class Foo { ... </configuration> </pre> - <p>If no unit of time is specified, then the unit of time is - assumed to be milliseconds, which is usually inappropriate. If you - change the default scanning period, do not forget to specify a time - unit. + <p><span class="label">Note</span> If no unit of time is specified, + then the unit of time is assumed to be milliseconds, which is + usually inappropriate. If you change the default scanning period, + do not forget to specify a time unit. </p> <p>Behind the scenes, when you set the scan attribute to true, a @@ -465,17 +465,25 @@ public class Foo { "myLogger.debug("hello");", and if the scan attribute is set to true, then <code>ReconfigureOnChangeFilter</code> will be invoked. Moreover, the said filter will be invoked even if - <code>myLogger</code> is disabled for the debug level. + <code>myLogger</code> is disabled for the DEBUG level. </p> <p>Given that <code>ReconfigureOnChangeFilter</code> is invoked - every time <em>any</em> logger is invoked, the filter is - performance critical. In order to improve performance, instead of - checking whether to scan or not on every logger invocation, + every time <em>any</em> logger is invoked, regardless of logger + level, <code>ReconfigureOnChangeFilter</code> is absolutely + performance critical. So much so that in fact, the check whether + the scan period has elapsed or not, is too costly in itself. In + order to improve performance, <code>ReconfigureOnChangeFilter</code> is in reality "alive" only - once every 16 logging operations. In short, when a configuration - file changes, it will be automatically reloaded after a delay - determined by the scanning period and several logger invocations. + once every <em>N</em> logging operations. Depending on how often + your application logs, the value of <em>N</em> can be modified on + the fly by logback. By default N is 16, altough it can go as high + as 2^16 (= 65536) for CPU-intensive applications. + </p> + + <p>In short, when a configuration file changes, it will be + automatically reloaded but only after several logger invocations + <em>and</em> after a delay determined by the scanning period. </p> diff --git a/logback-site/src/site/pages/news.html b/logback-site/src/site/pages/news.html index 6b88b35..7d9d0f4 100644 --- a/logback-site/src/site/pages/news.html +++ b/logback-site/src/site/pages/news.html @@ -29,9 +29,31 @@ <hr width="80%" align="center" /> - <h3>Xth of April, 2012 - Release of version 1.0.2</h3> + <h3>26th of April, 2012 - Release of version 1.0.2</h3> + <div style="border: 1px solid #F44; background-color: #FED; padding-left: 1ex; padding-right: 1ex;"> + + <h4>Breaking change: <code>PatternLayout</code> will now output + its pattern at the top of log files</h4> + + <p>In order to facilitate parsing of log files, logback now + inserts the pattern used for the log output at the top of each log + file. This feature was requested by James Strachan in <a + href="http://jira.qos.ch/browse/LBCORE-234">LBCORE-234</a>. + </p> + + <p>Here an example:</p> + <pre>#logback.classic pattern: %d [%thread] %-5level %logger{36} - %msg%n +2012-04-26 14:54:38,461 [main] DEBUG com.foo.App - Hello world +2012-04-26 14:54:38,461 [main] DEBUG com.foo.App - Hi again +...</pre> + + <p>The line starting with "#logback.classic pattern" is newly + inserted pattern line.</p> + + </div> + <p><code>ReconfigureOnChangeFilter</code> will avoid excessive syncronization in case of CPU intensive applications. This fixes <a ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 24 +++++++++++---- .../test/input/turbo/inclusion/topByResource.xml | 2 +- .../src/test/input/turbo/inclusion/topLevel0.xml | 2 +- logback-classic/src/test/input/turbo/scan_perf.xml | 2 +- .../issue/lbclassic135/LoggingRunnable.java | 2 +- .../classic/turbo/ReconfigureOnChangeTest.java | 7 ---- .../qos/logback/classic/turbo/ReconfigurePerf.java | 2 +- .../src/site/pages/manual/configuration.html | 30 ++++++++++++------- logback-site/src/site/pages/news.html | 24 +++++++++++++++- 9 files changed, 64 insertions(+), 31 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-30-g369b71c
by git-noreply＠pixie.qos.ch 26 Apr '12

26 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via 369b71c9c28d38dd45af49925d88d4853fb6679a (commit) from e1750a116b652ae912d9da35c22de07947762f05 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=369b71c9c28d38dd45af4992… http://github.com/ceki/logback/commit/369b71c9c28d38dd45af49925d88d4853fb66… commit 369b71c9c28d38dd45af49925d88d4853fb6679a Author: Ceki Gulcu <ceki(a)qos.ch> Date: Thu Apr 26 09:54:38 2012 +0200 have tests pass diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index 741bf88..08869c3 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -125,7 +125,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { // for CPU intensive applications with 200 or more threads MASK values in the order of 0xFFFF is appropriate private static final int MAX_MASK = 0xFFFF; - // update the mask so as to execute change detection code about once every 1s. + // update the mask so as to execute change detection code about once every 1 to 8 seconds. private void updateMaskIfNecessary(long now) { // if less than 1s elapsed since last maskUpdate double the mask size and add 1 final long timeElapsedSinceLastCheck = now - lastMaskCheck; diff --git a/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/FileNamePatternTest.java b/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/FileNamePatternTest.java index 115bd6c..4eb7c18 100644 --- a/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/FileNamePatternTest.java +++ b/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/FileNamePatternTest.java @@ -115,13 +115,13 @@ public class FileNamePatternTest { FileNamePattern fnp = new FileNamePattern("foo-%d{yyyy.MM.dd}-%i.txt", context); String regex = fnp.toRegex(cal.getTime()); - assertEquals("foo-2003.05.20-(\\d{1,2}).txt", regex); + assertEquals("foo-2003.05.20-(\\d{1,3}).txt", regex); } { FileNamePattern fnp = new FileNamePattern("\\toto\\foo-%d{yyyy\\MM\\dd}-%i.txt", context); String regex = fnp.toRegex(cal.getTime()); - assertEquals("/toto/foo-2003/05/20-(\\d{1,2}).txt", regex); + assertEquals("/toto/foo-2003/05/20-(\\d{1,3}).txt", regex); } } ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 2 +- .../core/rolling/helper/FileNamePatternTest.java | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-29-ge1750a1
by git-noreply＠pixie.qos.ch 25 Apr '12

25 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via e1750a116b652ae912d9da35c22de07947762f05 (commit) from 608ed4c58717296b8182006e35aff52ca2ecb598 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=e1750a116b652ae912d9da35… http://github.com/ceki/logback/commit/e1750a116b652ae912d9da35c22de07947762… commit e1750a116b652ae912d9da35c22de07947762f05 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Thu Apr 26 00:14:12 2012 +0200 slightly better logic in updateMaskIfNecessary diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index c812c2b..741bf88 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -84,7 +84,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { // IMPORTANT: This field can be updated by multiple threads. It follows that // its values may *not* be incremented sequentially. However, we don't care // about the actual value of the field except that from time to time the - // expression (invocationCounter++ & 0xF) == 0xF) should be true. + // expression (invocationCounter++ & mask) == mask) should be true. private long invocationCounter = 0; private volatile long mask = 0xF; @@ -98,8 +98,9 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return FilterReply.NEUTRAL; } - // for performance reasons, skip any type of computation (MASK-1) times out of MASK. - // Only once every MASK calls is the check for elapsed time is performed + // for performance reasons, skip change detection (MASK-1) times out of MASK. + // Only once every MASK calls is change detection code executed + // Note that MASK is a variable itself. if (((invocationCounter++) & mask) != mask) { return FilterReply.NEUTRAL; } @@ -124,15 +125,16 @@ public class ReconfigureOnChangeFilter extends TurboFilter { // for CPU intensive applications with 200 or more threads MASK values in the order of 0xFFFF is appropriate private static final int MAX_MASK = 0xFFFF; + // update the mask so as to execute change detection code about once every 1s. private void updateMaskIfNecessary(long now) { - if (now - lastMaskCheck < MILLIS_IN_ONE_SECOND) { - if (mask < MAX_MASK) { + // if less than 1s elapsed since last maskUpdate double the mask size and add 1 + final long timeElapsedSinceLastCheck = now - lastMaskCheck; + lastMaskCheck = now; + if (timeElapsedSinceLastCheck < MILLIS_IN_ONE_SECOND && (mask < MAX_MASK)) { mask = (mask << 1) | 1; - } - } else { + } else if (timeElapsedSinceLastCheck > 8*MILLIS_IN_ONE_SECOND) { mask = mask >>> 2; } - lastMaskCheck = now; } // by detaching reconfiguration to a new thread, we release the various ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 18 ++++++++++-------- 1 files changed, 10 insertions(+), 8 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[JIRA] Created: (LBCLASSIC-234) CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide
by uri unger (JIRA) 25 Apr '12

25 Apr '12

CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide -------------------------------------------------------------------- Key: LBCLASSIC-234 URL: http://jira.qos.ch/browse/LBCLASSIC-234 Project: logback-classic Issue Type: Bug Affects Versions: 0.917 Reporter: uri unger Assignee: Ceki Gulcu The synchronization in ReconfigureOnChangeFilter.decide hurts scalability. It seems unnecessary to serialize the code in changeDetected -- it should be possible to use atomic updates of nextCheck and lastModified and only serialize the actual reconfiguration. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

6 18

[JIRA] Created: (LBCORE-221) Error in FileNamePattern::toRegex for index (Integer)
by Dieter Mueller (JIRA) 25 Apr '12

25 Apr '12

Error in FileNamePattern::toRegex for index (Integer) ----------------------------------------------------- Key: LBCORE-221 URL: http://jira.qos.ch/browse/LBCORE-221 Project: logback-core Issue Type: Bug Components: Pattern, Rolling Affects Versions: 0.9.29 Reporter: Dieter Mueller Assignee: Logback dev list Priority: Minor Deletion of old archived logs on rolling failes for index > 99. We have a process which logs much, which results in more than 99 log files per day (config below), e.g. snowball_POLL_MSG_SRV_xdebug-old-2011-09-13.110.log.zip. On rolling event, only the first 99 were deleted, due to bug in FileNamePattern::toRegex for index (Integer): regEx: \d{1,2) which means digits with max length of 2. We need at least 3 digits: regEx: \d{1,3) better 4? ;-) Workarounds like increasing file size, or hourly-rollover to hold index lower than 100 are not very wellcomed. Thanks in advance, Dieter Mueller. config: <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  <fileNamePattern>${log.vm.file.prefix}_xdebug-old-%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern> <maxHistory>1</maxHistory> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <maxFileSize>20MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

3 2

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-28-g608ed4c
by git-noreply＠pixie.qos.ch 25 Apr '12

25 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via 608ed4c58717296b8182006e35aff52ca2ecb598 (commit) via 1f6b71923bfeb5d273a80388e7dca2edab02677c (commit) from d886e9b0aa31036bf5bf5c5b78249afb50a80d6c (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=608ed4c58717296b8182006e… http://github.com/ceki/logback/commit/608ed4c58717296b8182006e35aff52ca2ecb… commit 608ed4c58717296b8182006e35aff52ca2ecb598 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Wed Apr 25 23:47:18 2012 +0200 fix LBCORE-221 diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index c038354..c812c2b 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -33,6 +33,8 @@ import ch.qos.logback.classic.joran.JoranConfigurator; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.spi.FilterReply; +import static ch.qos.logback.core.CoreConstants.MILLIS_IN_ONE_SECOND; + /** * Reconfigure a LoggerContext when the configuration file changes. * @@ -44,7 +46,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { * Scan for changes in configuration file once every minute. */ // 1 minute - value mentioned in documentation - public final static long DEFAULT_REFRESH_PERIOD = 60 * 1000; + public final static long DEFAULT_REFRESH_PERIOD = 60 * MILLIS_IN_ONE_SECOND; long refreshPeriod = DEFAULT_REFRESH_PERIOD; URL mainConfigurationURL; @@ -85,6 +87,10 @@ public class ReconfigureOnChangeFilter extends TurboFilter { // expression (invocationCounter++ & 0xF) == 0xF) should be true. private long invocationCounter = 0; + private volatile long mask = 0xF; + private long lastMaskCheck = System.currentTimeMillis(); + + @Override public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) { @@ -92,14 +98,17 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return FilterReply.NEUTRAL; } - // for performance reasons, skip any type of computation 15 times out of 16. - // Only once every 16 calls is the check for elapsed type is performed - if (((invocationCounter++) & 0xF) != 0xF) { + // for performance reasons, skip any type of computation (MASK-1) times out of MASK. + // Only once every MASK calls is the check for elapsed time is performed + if (((invocationCounter++) & mask) != mask) { return FilterReply.NEUTRAL; } + long now = System.currentTimeMillis(); + synchronized (configurationWatchList) { - if (changeDetected()) { + updateMaskIfNecessary(now); + if (changeDetected(now)) { // Even though reconfiguration involves resetting the loggerContext, // which clears the list of turbo filters including this instance, it is // still possible for this instance to be subsequently invoked by another @@ -112,6 +121,20 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return FilterReply.NEUTRAL; } + // for CPU intensive applications with 200 or more threads MASK values in the order of 0xFFFF is appropriate + private static final int MAX_MASK = 0xFFFF; + + private void updateMaskIfNecessary(long now) { + if (now - lastMaskCheck < MILLIS_IN_ONE_SECOND) { + if (mask < MAX_MASK) { + mask = (mask << 1) | 1; + } + } else { + mask = mask >>> 2; + } + lastMaskCheck = now; + } + // by detaching reconfiguration to a new thread, we release the various // locks held by the current thread, in particular, the AppenderAttachable // reader lock. @@ -124,8 +147,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { nextCheck = now + refreshPeriod; } - protected boolean changeDetected() { - long now = System.currentTimeMillis(); + protected boolean changeDetected(long now) { if (now >= nextCheck) { updateNextCheck(now); return configurationWatchList.changeDetected(); @@ -152,7 +174,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return; } LoggerContext lc = (LoggerContext) context; - addInfo(CoreConstants.RESET_MSG_PREFIX + "named ["+context.getName() + "]"); + addInfo(CoreConstants.RESET_MSG_PREFIX + "named [" + context.getName() + "]"); if (mainConfigurationURL.toString().endsWith("xml")) { performXMLConfiguration(lc); } else if (mainConfigurationURL.toString().endsWith("groovy")) { diff --git a/logback-classic/src/test/input/turbo/scan_perf.xml b/logback-classic/src/test/input/turbo/scan_perf.xml index a5bc569..d652491 100644 --- a/logback-classic/src/test/input/turbo/scan_perf.xml +++ b/logback-classic/src/test/input/turbo/scan_perf.xml @@ -13,7 +13,8 @@ </appender> - <root level="DEBUG"> +  + <root level="ERROR"> <appender-ref ref="FILE"/> </root> diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java index b8ce4bd..dd93afb 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigurePerf.java @@ -17,6 +17,7 @@ import java.io.File; import java.io.IOException; import org.junit.Before; +import org.junit.Ignore; import org.junit.Test; import ch.qos.logback.classic.ClassicTestConstants; @@ -29,14 +30,15 @@ import ch.qos.logback.core.contention.RunnableWithCounterAndDone; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.testUtil.Env; +@Ignore public class ReconfigurePerf { - final static int THREAD_COUNT = 50; + final static int THREAD_COUNT = 500; //final static int LOOP_LEN = 1000 * 1000; // the space in the file name mandated by // http://jira.qos.ch/browse/LBCORE-119 final static String CONF_FILE_AS_STR = ClassicTestConstants.INPUT_PREFIX - + "turbo/scan_perf_barebones.xml"; + + "turbo/scan_perf.xml"; // it actually takes time for Windows to propagate file modification changes // values below 100 milliseconds can be problematic the same propagation @@ -45,6 +47,7 @@ public class ReconfigurePerf { int sleepBetweenUpdates = DEFAULT_SLEEP_BETWEEN_UPDATES; + static int numberOfCycles = 150; static int totalTestDuration; LoggerContext loggerContext = new LoggerContext(); @@ -56,9 +59,9 @@ public class ReconfigurePerf { // take into account propagation latency occurs on Linux if (Env.isLinux()) { sleepBetweenUpdates = 850; - totalTestDuration = sleepBetweenUpdates * 25; + totalTestDuration = sleepBetweenUpdates * numberOfCycles; } else { - totalTestDuration = sleepBetweenUpdates * 50; + totalTestDuration = sleepBetweenUpdates * numberOfCycles * 2; } harness = new MultiThreadedHarness(totalTestDuration); } @@ -82,11 +85,7 @@ public class ReconfigurePerf { public void scan1() throws JoranException, IOException, InterruptedException { File file = new File(CONF_FILE_AS_STR); configure(file); - //doRun(); - //doRun(); - //doRun(); - System.out.println("ENTER :"); - //System.in.read(); + System.out.println("Running scan1()"); doRun(); } @@ -94,29 +93,4 @@ public class ReconfigurePerf { RunnableWithCounterAndDone[] runnableArray = buildRunnableArray(); harness.execute(runnableArray); } - -// ReconfigureOnChangeFilter initROCF() throws MalformedURLException { -// ReconfigureOnChangeFilter rocf = new ReconfigureOnChangeFilter(); -// rocf.setContext(loggerContext); -// File file = new File(CONF_FILE_AS_STR); -// loggerContext.putObject(CoreConstants.URL_OF_LAST_CONFIGURATION_VIA_JORAN, -// file.toURI().toURL()); -// rocf.start(); -// return rocf; -// } - - -// public double directLoop(ReconfigureOnChangeFilter rocf) { -// long start = System.nanoTime(); -// for (int i = 0; i < LOOP_LEN; i++) { -// rocf.decide(null, logger, Level.DEBUG, " ", null, null); -// } -// long end = System.nanoTime(); -// return (end - start) / (1.0d * LOOP_LEN); -// } -// -// void addInfo(String msg, Object o) { -// loggerContext.getStatusManager().add(new InfoStatus(msg, o)); -// } - } diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/FileNamePattern.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/FileNamePattern.java index dab1a72..c96d515 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/FileNamePattern.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/FileNamePattern.java @@ -165,7 +165,7 @@ public class FileNamePattern extends ContextAwareBase { if (p instanceof LiteralConverter) { buf.append(p.convert(null)); } else if (p instanceof IntegerTokenConverter) { - buf.append("(\\d{1,2})"); + buf.append("(\\d{1,3})"); } else if (p instanceof DateTokenConverter) { buf.append(p.convert(date)); } diff --git a/logback-site/src/site/pages/news.html b/logback-site/src/site/pages/news.html index 37ba9ff..6b88b35 100644 --- a/logback-site/src/site/pages/news.html +++ b/logback-site/src/site/pages/news.html @@ -31,12 +31,27 @@ <h3>Xth of April, 2012 - Release of version 1.0.2</h3> + + <p><code>ReconfigureOnChangeFilter</code> will avoid excessive + syncronization in case of CPU intensive applications. This fixes + <a + href="http://jira.qos.ch/browse/LBCLASSIC-234">LBCLASSIC-234</a>, + a recalcitrant bug reported by Uri Unger who also provided the key + steps for reproducing it. + </p> + <p><code>RollingFileAppender</code> now creates missing directories for compressed archive files. This fixes <a href="http://jira.qos.ch/browse/LBCORE-169">LBCORE-169</a> - reported by Tomasz Nurkiewicz with patchessupplied by Paulo + reported by Tomasz Nurkiewicz with patches supplied by Paulo Andrade and Mats Henrikson. </p> + + <p><code>SizeAndTimeBasedFNATP</code> will now remove files with + indexes higher than 99. It will also correctly compute the highest + index value when an application is restarted. This fixes bug <a + href="http://jira.qos.ch/browse/LBCORE-221">LBCORE-221</a> + reported by Dieter Mueller and Dawid Chodura.</p> <hr width="80%" align="center" /> http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=1f6b71923bfeb5d273a80388… http://github.com/ceki/logback/commit/1f6b71923bfeb5d273a80388e7dca2edab026… commit 1f6b71923bfeb5d273a80388e7dca2edab02677c Author: Ceki Gulcu <ceki(a)qos.ch> Date: Tue Apr 24 20:05:57 2012 +0200 added blurb on LBCORE-169 diff --git a/logback-site/src/site/pages/news.html b/logback-site/src/site/pages/news.html index ef261da..37ba9ff 100644 --- a/logback-site/src/site/pages/news.html +++ b/logback-site/src/site/pages/news.html @@ -29,6 +29,18 @@ <hr width="80%" align="center" /> + <h3>Xth of April, 2012 - Release of version 1.0.2</h3> + + <p><code>RollingFileAppender</code> now creates missing + directories for compressed archive files. This fixes <a + href="http://jira.qos.ch/browse/LBCORE-169">LBCORE-169</a> + reported by Tomasz Nurkiewicz with patchessupplied by Paulo + Andrade and Mats Henrikson. + </p> + + + <hr width="80%" align="center" /> + <h3>7th of March, 2012 - Release of version 1.0.1</h3> <p>Setting the debug attribute to true in the ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 38 ++++++++++++++---- logback-classic/src/test/input/turbo/scan_perf.xml | 3 +- .../qos/logback/classic/turbo/ReconfigurePerf.java | 42 ++++---------------- .../core/rolling/helper/FileNamePattern.java | 2 +- logback-site/src/site/pages/news.html | 27 +++++++++++++ 5 files changed, 68 insertions(+), 44 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[JIRA] Created: (LBACCESS-30) Netty Support
by Brian Guan (JIRA) 24 Apr '12

24 Apr '12

Netty Support ------------- Key: LBACCESS-30 URL: http://jira.qos.ch/browse/LBACCESS-30 Project: logback-access Issue Type: New Feature Components: Other Environment: Netty Reporter: Brian Guan Assignee: Logback dev list I was looking for a Netty http access logging solution and found logback-access via Googling. Since you only have support for Tomcat and Jetty and other servlet container, I wonder if a Netty solution would be useful. Since Netty is NOT a container in the J2EE sense, it only allows programmatic extension by inserting channel handler(s) into its pipeline. I have coded an experimental toy project based on this design but without using Logback yet. Questions to the community: * are you using Netty? * would you envision people using Netty and wanting logback-access? * would you like to see Netty support as part of logback-access? -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

2 1

[JIRA] Created: (LBCORE-169) RollingFileAppender/TimeBasedRollingPolicy failing to ZIP files in different directory
by Tomasz Nurkiewicz (JIRA) 24 Apr '12

24 Apr '12

RollingFileAppender/TimeBasedRollingPolicy failing to ZIP files in different directory -------------------------------------------------------------------------------------- Key: LBCORE-169 URL: http://jira.qos.ch/browse/LBCORE-169 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.24 Reporter: Tomasz Nurkiewicz Assignee: Logback dev list When using ZIP feature to compress old log files, Logback does not allow to put ZIP files in different directory like in this example: <file>logs\server.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs\arch\server.%d{yyyy-MM-dd_HHmm}.log.zip</fileNamePattern> </rollingPolicy> Running the attached test maven project (it takes 1 minute to run) will create server.log3560979839057.tmp (or similar) temporary file instead of ZIP file in /arch subdirectory (preferably this directory should be created if not exists). If fileNamePattern in rollingPolicy is changed to: "logs\server.%d{yyyy-MM-dd_HHmm}.log.zip" everything works as expected. The root of this issue is to be able to automatically ZIP files AND archive them in different directory. It would be great to be able to use date placeholders in folder names, for instance: <fileNamePattern>logs\arch-%d{yyyy-MM}\server.%d{yyyy-MM-dd_HHmm}.log.zip</fileNamePattern> so that Logback would automatically create folders for each month with ZIPped files. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

8 9

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-26-gd886e9b
by git-noreply＠pixie.qos.ch 24 Apr '12

24 Apr '12

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via d886e9b0aa31036bf5bf5c5b78249afb50a80d6c (commit) from 560596f736cc1bf37171bd4d5d19dfc96a625550 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=d886e9b0aa31036bf5bf5c5b… http://github.com/ceki/logback/commit/d886e9b0aa31036bf5bf5c5b78249afb50a80… commit d886e9b0aa31036bf5bf5c5b78249afb50a80d6c Author: Ceki Gulcu <ceki(a)qos.ch> Date: Tue Apr 24 19:50:59 2012 +0200 fix LBCORE-169 diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java index b5a05da..69d8b42 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java @@ -55,7 +55,6 @@ abstract public class TimeBasedFileNamingAndTriggeringPolicyBase<E> extends + "'."); rc.printPeriodicity(this); - setDateInCurrentPeriod(new Date(getCurrentTime())); if (tbrp.getParentsRawFileProperty() != null) { File currentFile = new File(tbrp.getParentsRawFileProperty()); diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/Compressor.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/Compressor.java index 0132322..5e139e1 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/Compressor.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/Compressor.java @@ -22,14 +22,16 @@ import java.util.zip.GZIPOutputStream; import java.util.zip.ZipEntry; import java.util.zip.ZipOutputStream; +import ch.qos.logback.core.rolling.RolloverFailure; import ch.qos.logback.core.spi.ContextAwareBase; import ch.qos.logback.core.status.ErrorStatus; import ch.qos.logback.core.status.WarnStatus; +import ch.qos.logback.core.util.FileUtil; /** * The <code>Compression</code> class implements ZIP and GZ file * compression/decompression methods. - * + * * @author Ceki Gülcü */ public class Compressor extends ContextAwareBase { @@ -40,25 +42,22 @@ public class Compressor extends ContextAwareBase { this.compressionMode = compressionMode; } - /** - * - * @param nameOfFile2Compress - * @param nameOfCompressedFile - * @param innerEntryName The name of the file within the zip file. Use for ZIP compression. - */ + /** + * @param nameOfFile2Compress + * @param nameOfCompressedFile + * @param innerEntryName The name of the file within the zip file. Use for ZIP compression. + */ public void compress(String nameOfFile2Compress, String nameOfCompressedFile, String innerEntryName) { switch (compressionMode) { - case GZ: - addInfo("GZ compressing [" + nameOfFile2Compress + "]."); - gzCompress(nameOfFile2Compress, nameOfCompressedFile); - break; - case ZIP: - addInfo("ZIP compressing [" + nameOfFile2Compress + "]."); - zipCompress(nameOfFile2Compress, nameOfCompressedFile, innerEntryName); - break; - case NONE: - throw new UnsupportedOperationException( - "compress method called in NONE compression mode"); + case GZ: + gzCompress(nameOfFile2Compress, nameOfCompressedFile); + break; + case ZIP: + zipCompress(nameOfFile2Compress, nameOfCompressedFile, innerEntryName); + break; + case NONE: + throw new UnsupportedOperationException( + "compress method called in NONE compression mode"); } } @@ -67,12 +66,12 @@ public class Compressor extends ContextAwareBase { if (!file2zip.exists()) { addStatus(new WarnStatus("The file to compress named [" + nameOfFile2zip - + "] does not exist.", this)); + + "] does not exist.", this)); return; } - if(innerEntryName == null) { + if (innerEntryName == null) { addStatus(new WarnStatus("The innerEntryName parameter cannot be null", this)); return; } @@ -85,11 +84,14 @@ public class Compressor extends ContextAwareBase { if (zippedFile.exists()) { addStatus(new WarnStatus("The target compressed file named [" - + nameOfZippedFile + "] exist already.", this)); + + nameOfZippedFile + "] exist already.", this)); return; } + addInfo("ZIP compressing [" + file2zip + "] as ["+zippedFile+"]"); + createMissingTargetDirsIfNecessary(zippedFile); + BufferedInputStream bis = null; ZipOutputStream zos = null; try { @@ -113,20 +115,20 @@ public class Compressor extends ContextAwareBase { if (!file2zip.delete()) { addStatus(new WarnStatus("Could not delete [" + nameOfFile2zip + "].", - this)); + this)); } } catch (Exception e) { addStatus(new ErrorStatus("Error occurred while compressing [" - + nameOfFile2zip + "] into [" + nameOfZippedFile + "].", this, e)); + + nameOfFile2zip + "] into [" + nameOfZippedFile + "].", this, e)); } finally { - if(bis != null) { + if (bis != null) { try { bis.close(); } catch (IOException e) { // ignore } } - if(zos != null) { + if (zos != null) { try { zos.close(); } catch (IOException e) { @@ -168,11 +170,12 @@ public class Compressor extends ContextAwareBase { if (!file2gz.exists()) { addStatus(new WarnStatus("The file to compress named [" + nameOfFile2gz - + "] does not exist.", this)); + + "] does not exist.", this)); return; } + if (!nameOfgzedFile.endsWith(".gz")) { nameOfgzedFile = nameOfgzedFile + ".gz"; } @@ -180,12 +183,14 @@ public class Compressor extends ContextAwareBase { File gzedFile = new File(nameOfgzedFile); if (gzedFile.exists()) { - addStatus(new WarnStatus("The target compressed file named [" - + nameOfgzedFile + "] exist already.", this)); - + addWarn("The target compressed file named [" + + nameOfgzedFile + "] exist already. Aborting file compression."); return; } + addInfo("GZ compressing [" + file2gz + "] as ["+gzedFile+"]"); + createMissingTargetDirsIfNecessary(gzedFile); + BufferedInputStream bis = null; GZIPOutputStream gzos = null; try { @@ -205,20 +210,20 @@ public class Compressor extends ContextAwareBase { if (!file2gz.delete()) { addStatus(new WarnStatus("Could not delete [" + nameOfFile2gz + "].", - this)); + this)); } } catch (Exception e) { addStatus(new ErrorStatus("Error occurred while compressing [" - + nameOfFile2gz + "] into [" + nameOfgzedFile + "].", this, e)); + + nameOfFile2gz + "] into [" + nameOfgzedFile + "].", this, e)); } finally { - if(bis != null) { + if (bis != null) { try { bis.close(); } catch (IOException e) { // ignore } } - if(gzos != null) { + if (gzos != null) { try { gzos.close(); } catch (IOException e) { @@ -233,24 +238,38 @@ public class Compressor extends ContextAwareBase { int len = fileNamePatternStr.length(); switch (compressionMode) { case GZ: - if(fileNamePatternStr.endsWith(".gz")) - return fileNamePatternStr.substring(0, len - 3); - else - return fileNamePatternStr; + if (fileNamePatternStr.endsWith(".gz")) + return fileNamePatternStr.substring(0, len - 3); + else + return fileNamePatternStr; case ZIP: - if(fileNamePatternStr.endsWith(".zip")) - return fileNamePatternStr.substring(0, len - 4); - else - return fileNamePatternStr; + if (fileNamePatternStr.endsWith(".zip")) + return fileNamePatternStr.substring(0, len - 4); + else + return fileNamePatternStr; case NONE: return fileNamePatternStr; } throw new IllegalStateException("Execution should not reach this point"); } + + void createMissingTargetDirsIfNecessary(File file) { + if (FileUtil.isParentDirectoryCreationRequired(file)) { + boolean result = FileUtil.createMissingParentDirectories(file); + if (!result) { + addError("Failed to create parent directories for [" + + file.getAbsolutePath() + "]"); + } else { + addInfo("Created missing parent directories for [" + + file.getAbsolutePath() + "]"); + } + } + } + @Override public String toString() { - return "c.q.l.core.rolling.helper.Compress"; + return this.getClass().getName(); } } diff --git a/logback-core/src/test/java/ch/qos/logback/core/util/Compare.java b/logback-core/src/test/java/ch/qos/logback/core/util/Compare.java index 536c1ba..1f21128 100644 --- a/logback-core/src/test/java/ch/qos/logback/core/util/Compare.java +++ b/logback-core/src/test/java/ch/qos/logback/core/util/Compare.java @@ -19,7 +19,11 @@ import java.io.FileNotFoundException; import java.io.FileReader; import java.io.IOException; import java.io.InputStreamReader; +import java.util.Enumeration; import java.util.zip.GZIPInputStream; +import java.util.zip.ZipEntry; +import java.util.zip.ZipFile; +import java.util.zip.ZipInputStream; public class Compare { static final int B1_NULL = -1; @@ -27,8 +31,9 @@ public class Compare { public static boolean compare(String file1, String file2) throws FileNotFoundException, IOException { if (file1.endsWith(".gz")) { - //System.out.println(file1 +" is a gz file"); return gzFileCompare(file1, file2); + } else if(file1.endsWith(".zip")) { + return zipFileCompare(file1, file2); } else { return regularFileCompare(file1, file2); } @@ -39,13 +44,24 @@ public class Compare { GZIPInputStream gzis = new GZIPInputStream(fis); return new BufferedReader(new InputStreamReader(gzis)); } - + + static BufferedReader zipFileToBufferedReader(String file) throws IOException { + FileInputStream fis = new FileInputStream(file); + ZipInputStream zis = new ZipInputStream(fis); + zis.getNextEntry(); + return new BufferedReader(new InputStreamReader(zis)); + } public static boolean gzFileCompare(String file1, String file2) throws IOException { BufferedReader in1 = gzFileToBufferedReader(file1); BufferedReader in2 = gzFileToBufferedReader(file2); return bufferCompare(in1, in2, file1, file2); } + public static boolean zipFileCompare(String file1, String file2) throws IOException { + BufferedReader in1 = zipFileToBufferedReader(file1); + BufferedReader in2 = zipFileToBufferedReader(file2); + return bufferCompare(in1, in2, file1, file2); + } public static boolean regularFileCompare(String file1, String file2) throws FileNotFoundException, IOException { BufferedReader in1 = new BufferedReader(new FileReader(file1)); diff --git a/logback-core/src/test/scala/ch/qos/logback/core/rolling/RollingScaffolding.scala b/logback-core/src/test/scala/ch/qos/logback/core/rolling/RollingScaffolding.scala index b88b50b..0f54d19 100644 --- a/logback-core/src/test/scala/ch/qos/logback/core/rolling/RollingScaffolding.scala +++ b/logback-core/src/test/scala/ch/qos/logback/core/rolling/RollingScaffolding.scala @@ -6,7 +6,7 @@ * either the terms of the Eclipse Public License v1.0 as published by * the Eclipse Foundation * - * or (per the licensee's choosing) + * or (per the licensee's choosing) * * under the terms of the GNU Lesser General Public License version 2.1 * as published by the Free Software Foundation. @@ -14,7 +14,7 @@ package ch.qos.logback.core.rolling import ch.qos.logback.core.{ContextBase, Context} -import helper.FileFilterUtil +import helper.{FileNamePattern, FileFilterUtil} import java.util.concurrent.TimeUnit import ch.qos.logback.core.util.{CachingDateFormatter, CoreTestConstants} import org.junit.Assert._ @@ -29,7 +29,7 @@ trait RollingScaffolding { val context: Context = new ContextBase val sm = context.getStatusManager() - + var diff: Int = RandomUtil.getPositiveInt protected var currentTime: Long = 0L @@ -63,24 +63,23 @@ trait RollingScaffolding { return new Date(currentTime - delta) } - protected def addExpectedFileName_ByDate(outputDir: String, testId: String, millis: Long, gzExtension: Boolean): Unit = { - var fn: String = outputDir + testId + "-" + SDF.format(millis) - if (gzExtension) { - fn += ".gz" - } + protected def addExpectedFileName_ByDate(patternStr: String, millis: Long): Unit = { + val fileNamePattern = new FileNamePattern(patternStr, context) + var fn: String = fileNamePattern.convert(new Date(millis)) + println("fn=" + fn) expectedFilenameList = expectedFilenameList ::: List(fn) } protected def addExpectedFileName_ByFileIndexCounter(randomOutputDir: String, testId: String, millis: Long, fileIndexCounter: Int, compressionSuffix: String): Unit = { - var fn: String = randomOutputDir + testId + "-" + SDF.format(millis) + "-" + fileIndexCounter + ".txt"+compressionSuffix + var fn: String = randomOutputDir + testId + "-" + SDF.format(millis) + "-" + fileIndexCounter + ".txt" + compressionSuffix expectedFilenameList = expectedFilenameList ::: List(fn) } - - protected def addExpectedFileNamedIfItsTime_ByDate(outputDir: String, testId: String, gzExtension: Boolean): Unit = { + + protected def addExpectedFileNamedIfItsTime_ByDate(fileNamePatternStr: String): Unit = { if (passThresholdTime(nextRolloverThreshold)) { - addExpectedFileName_ByDate(outputDir, testId, getMillisOfCurrentPeriodsStart, gzExtension) + addExpectedFileName_ByDate(fileNamePatternStr, getMillisOfCurrentPeriodsStart) recomputeRolloverThreshold(currentTime) } } @@ -112,9 +111,16 @@ trait RollingScaffolding { // ========================================================================= // utility methods // ========================================================================= - private[rolling] def massageExpectedFilesToCorresponToCurrentTarget(file: String): Unit = { + private[rolling] def massageExpectedFilesToCorresponToCurrentTarget(file: String, fileOptionIsSet: Boolean): Unit = { + val last: String = expectedFilenameList.last expectedFilenameList = expectedFilenameList.dropRight(1) - expectedFilenameList = expectedFilenameList ::: List(file) + + if (fileOptionIsSet) { + expectedFilenameList = expectedFilenameList ::: List(file) + } else if (last.endsWith(".gz")) { + val stem = last.dropRight(3) + expectedFilenameList = expectedFilenameList ::: List(stem) + } } def existenceCheck(filenameList: List[String]): Unit = { @@ -133,7 +139,7 @@ trait RollingScaffolding { FileFilterUtil.sortFileArrayByName(fileArray) fileContentCheck(fileArray, runLength, prefix) } - + def reverseSortedContentCheck(outputDirStr: String, runLength: Int, prefix: String) { var fileArray: Array[File] = getFilesInDirectory(outputDirStr) FileFilterUtil.reverseSortFileArrayByName(fileArray) diff --git a/logback-core/src/test/scala/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP_STest.scala b/logback-core/src/test/scala/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP_STest.scala index 370323f..00caf98 100644 --- a/logback-core/src/test/scala/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP_STest.scala +++ b/logback-core/src/test/scala/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP_STest.scala @@ -106,9 +106,9 @@ class SizeAndTimeBasedFNATP_STest extends RollingScaffolding { secondPhase runLength = runLength*2 } - + if (stem != null) - massageExpectedFilesToCorresponToCurrentTarget(file) + massageExpectedFilesToCorresponToCurrentTarget(file, true) Thread.sleep(20) // wait for compression to finish diff --git a/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRolling_STest.scala b/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRolling_STest.scala index c2d8aa4..ce09a22 100644 --- a/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRolling_STest.scala +++ b/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRolling_STest.scala @@ -57,23 +57,24 @@ class TimeBasedRolling_STest extends RollingScaffolding { } type CheckFunction = ((String, Boolean, String) => Unit) - def genericTest(checkFunction: CheckFunction)(testId: String, compressionSuffix: String, fileOptionIsSet: Boolean, waitDuration: Int): Unit = { + def genericTest(checkFunction: CheckFunction)(testId: String, patternPrefix: String, compressionSuffix: String, fileOptionIsSet: Boolean, waitDuration: Int): Unit = { val withCompression = compressionSuffix.length > 0 val fileName = if (fileOptionIsSet) testId2FileName(testId) else null; initRFA(rfa1, fileName); - initTRBP(rfa1, tbrp1, randomOutputDir + testId + "-%d{" - + DATE_PATTERN_WITH_SECONDS + "}" + compressionSuffix, currentTime); + val fileNamePatternStr = randomOutputDir + patternPrefix + "-%d{"+ DATE_PATTERN_WITH_SECONDS + "}"+compressionSuffix + + initTRBP(rfa1, tbrp1, fileNamePatternStr, currentTime); // compute the current filename - addExpectedFileName_ByDate(randomOutputDir, testId, getMillisOfCurrentPeriodsStart, withCompression); + addExpectedFileName_ByDate(fileNamePatternStr, getMillisOfCurrentPeriodsStart); incCurrentTime(1100); tbrp1.timeBasedFileNamingAndTriggeringPolicy.setCurrentTime(currentTime); for (i <- 0 until 3) { rfa1.doAppend("Hello---" + i); - addExpectedFileNamedIfItsTime_ByDate(randomOutputDir, testId, withCompression && (i != 2)) + addExpectedFileNamedIfItsTime_ByDate(fileNamePatternStr) //, withCompression && (i != 2)) incCurrentTime(500); tbrp1.timeBasedFileNamingAndTriggeringPolicy.setCurrentTime(currentTime) if (withCompression) @@ -82,13 +83,12 @@ class TimeBasedRolling_STest extends RollingScaffolding { rfa1.stop if (waitDuration != NO_RESTART) { - doRestart(testId, fileOptionIsSet, waitDuration); + doRestart(testId, patternPrefix, fileOptionIsSet, waitDuration); } - if (fileOptionIsSet) { - massageExpectedFilesToCorresponToCurrentTarget(fileName) - } + massageExpectedFilesToCorresponToCurrentTarget(fileName, fileOptionIsSet) + StatusPrinter.print(context) checkFunction(testId, withCompression, compressionSuffix) } @@ -114,19 +114,21 @@ class TimeBasedRolling_STest extends RollingScaffolding { - def doRestart(testId: String, fileOptionIsSet: Boolean, waitDuration: Int) { + def doRestart(testId: String, patternPart: String, fileOptionIsSet: Boolean, waitDuration: Int) { // change the timestamp of the currently actively file var activeFile: File = new File(rfa1.getFile) activeFile.setLastModified(currentTime) incCurrentTime(waitDuration) + val filePatternStr = randomOutputDir + patternPart + "-%d{" + DATE_PATTERN_WITH_SECONDS + "}" + val fileName = if (fileOptionIsSet) testId2FileName(testId) else null; initRFA(rfa2, fileName) - initTRBP(rfa2, tbrp2, randomOutputDir + testId + "-%d{" + DATE_PATTERN_WITH_SECONDS + "}", currentTime) + initTRBP(rfa2, tbrp2, filePatternStr, currentTime) for (i <- 0 until 3) { rfa2.doAppend("World---" + i) - addExpectedFileNamedIfItsTime_ByDate(randomOutputDir, testId, false) + addExpectedFileNamedIfItsTime_ByDate(filePatternStr) incCurrentTime(100) tbrp2.timeBasedFileNamingAndTriggeringPolicy.setCurrentTime(currentTime) } @@ -138,44 +140,49 @@ class TimeBasedRolling_STest extends RollingScaffolding { @Test def noCompression_FileBlank_NoRestart_1 = { - defaultTest("test1", "", FILE_OPTION_BLANK, NO_RESTART) + defaultTest("test1", "test1", "", FILE_OPTION_BLANK, NO_RESTART) } @Test def withCompression_FileBlank_NoRestart_2 = { - defaultTest("test2", ".gz", FILE_OPTION_BLANK, NO_RESTART); + defaultTest("test2", "test2", ".gz", FILE_OPTION_BLANK, NO_RESTART); } @Test def noCompression_FileBlank_StopRestart_3 = { - defaultTest("test3", "", FILE_OPTION_BLANK, WITH_RESTART); + defaultTest("test3", "test3", "", FILE_OPTION_BLANK, WITH_RESTART); } @Test def noCompression_FileSet_StopRestart_4 = { - defaultTest("test4", "", FILE_OPTION_SET, WITH_RESTART); + defaultTest("test4", "test4", "", FILE_OPTION_SET, WITH_RESTART); } @Test def noCompression_FileSet_StopRestart_WithLongWait_4B = { - defaultTest("test4B", "", FILE_OPTION_SET, WITH_RESTART_AND_LONG_WAIT); + defaultTest("test4B", "test4B", "", FILE_OPTION_SET, WITH_RESTART_AND_LONG_WAIT); } @Test def noCompression_FileSet_NoRestart_5 = { - defaultTest("test5", "", FILE_OPTION_SET, NO_RESTART); + defaultTest("test5", "test6", "", FILE_OPTION_SET, NO_RESTART); } @Test def withCompression_FileSet_NoRestart_6 = { - defaultTest("test6", ".gz", FILE_OPTION_SET, NO_RESTART); + defaultTest("test6", "test6", ".gz", FILE_OPTION_SET, NO_RESTART); } + // LBCORE-169 @Test - def withMissingTargetDir = { - defaultTest("missingTargetDir", "", FILE_OPTION_SET, NO_RESTART); + def withMissingTargetDirWithCompression = { + defaultTest("test7", "%d{yyyy-MM-dd, aux}/", ".gz", FILE_OPTION_SET, NO_RESTART); } + @Test + def withMissingTargetDirWithZipCompression = { + defaultTest("test8", "%d{yyyy-MM-dd, aux}/", ".zip", FILE_OPTION_SET, NO_RESTART); + } @Test def failed_rename: Unit = { @@ -188,7 +195,7 @@ class TimeBasedRolling_STest extends RollingScaffolding { file.getParentFile.mkdirs fos = new FileOutputStream(fileName) - genericTest(zCheck)("failed_rename", "", FILE_OPTION_SET, NO_RESTART) + genericTest(zCheck)("failed_rename", "failed_rename", "", FILE_OPTION_SET, NO_RESTART) } finally { StatusPrinter.print(context) diff --git a/logback-core/src/test/witness/rolling/tbr-missingTargetDir.0 b/logback-core/src/test/witness/rolling/tbr-missingTargetDir.0 deleted file mode 100644 index e69de29..0000000 diff --git a/logback-core/src/test/witness/rolling/tbr-missingTargetDir.1 b/logback-core/src/test/witness/rolling/tbr-missingTargetDir.1 deleted file mode 100644 index aea23e8..0000000 --- a/logback-core/src/test/witness/rolling/tbr-missingTargetDir.1 +++ /dev/null @@ -1,2 +0,0 @@ -Hello---0 -Hello---1 \ No newline at end of file diff --git a/logback-core/src/test/witness/rolling/tbr-test7.0.gz b/logback-core/src/test/witness/rolling/tbr-test7.0.gz new file mode 100644 index 0000000..001322f Binary files /dev/null and b/logback-core/src/test/witness/rolling/tbr-test7.0.gz differ diff --git a/logback-core/src/test/witness/rolling/tbr-test7.1.gz b/logback-core/src/test/witness/rolling/tbr-test7.1.gz new file mode 100644 index 0000000..1a80ee1 Binary files /dev/null and b/logback-core/src/test/witness/rolling/tbr-test7.1.gz differ diff --git a/logback-core/src/test/witness/rolling/tbr-missingTargetDir.2 b/logback-core/src/test/witness/rolling/tbr-test7.2 similarity index 100% copy from logback-core/src/test/witness/rolling/tbr-missingTargetDir.2 copy to logback-core/src/test/witness/rolling/tbr-test7.2 diff --git a/logback-core/src/test/witness/rolling/tbr-test8.0.zip b/logback-core/src/test/witness/rolling/tbr-test8.0.zip new file mode 100644 index 0000000..0191c2a Binary files /dev/null and b/logback-core/src/test/witness/rolling/tbr-test8.0.zip differ diff --git a/logback-core/src/test/witness/rolling/tbr-test8.1.zip b/logback-core/src/test/witness/rolling/tbr-test8.1.zip new file mode 100644 index 0000000..621f821 Binary files /dev/null and b/logback-core/src/test/witness/rolling/tbr-test8.1.zip differ diff --git a/logback-core/src/test/witness/rolling/tbr-missingTargetDir.2 b/logback-core/src/test/witness/rolling/tbr-test8.2 similarity index 100% rename from logback-core/src/test/witness/rolling/tbr-missingTargetDir.2 rename to logback-core/src/test/witness/rolling/tbr-test8.2 ----------------------------------------------------------------------- Summary of changes: ...TimeBasedFileNamingAndTriggeringPolicyBase.java | 1 - .../logback/core/rolling/helper/Compressor.java | 103 ++++++++++++-------- .../java/ch/qos/logback/core/util/Compare.java | 20 ++++- .../logback/core/rolling/RollingScaffolding.scala | 36 ++++--- .../core/rolling/SizeAndTimeBasedFNATP_STest.scala | 4 +- .../core/rolling/TimeBasedRolling_STest.scala | 51 ++++++---- .../test/witness/rolling/tbr-missingTargetDir.1 | 2 - .../rolling/{tbr-test2.0.gz => tbr-test7.0.gz} | Bin 20 -> 20 bytes .../src/test/witness/rolling/tbr-test7.1.gz | Bin 0 -> 36 bytes .../{tbr-missingTargetDir.2 => tbr-test7.2} | 0 .../src/test/witness/rolling/tbr-test8.0.zip | Bin 0 -> 156 bytes .../src/test/witness/rolling/tbr-test8.1.zip | Bin 0 -> 172 bytes .../{tbr-missingTargetDir.2 => tbr-test8.2} | 0 13 files changed, 131 insertions(+), 86 deletions(-) delete mode 100644 logback-core/src/test/witness/rolling/tbr-missingTargetDir.0 delete mode 100644 logback-core/src/test/witness/rolling/tbr-missingTargetDir.1 copy logback-core/src/test/witness/rolling/{tbr-test2.0.gz => tbr-test7.0.gz} (100%) create mode 100644 logback-core/src/test/witness/rolling/tbr-test7.1.gz copy logback-core/src/test/witness/rolling/{tbr-missingTargetDir.2 => tbr-test7.2} (100%) create mode 100644 logback-core/src/test/witness/rolling/tbr-test8.0.zip create mode 100644 logback-core/src/test/witness/rolling/tbr-test8.1.zip rename logback-core/src/test/witness/rolling/{tbr-missingTargetDir.2 => tbr-test8.2} (100%) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0