[logback-dev] [GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_1.0.1-28-g608ed4c

Gitbot git-noreply at pixie.qos.ch
Wed Apr 25 23:47:57 CEST 2012


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=608ed4c58717296b8182006e35aff52ca2ecb598
http://github.com/ceki/logback/commit/608ed4c58717296b8182006e35aff52ca2ecb598

commit 608ed4c58717296b8182006e35aff52ca2ecb598
Author: Ceki Gulcu <ceki at 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">    
+  <!-- level should be ERROR so as not to incur IO -->
+  <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;
 
+ at 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=1f6b71923bfeb5d273a80388e7dca2edab02677c
http://github.com/ceki/logback/commit/1f6b71923bfeb5d273a80388e7dca2edab02677c

commit 1f6b71923bfeb5d273a80388e7dca2edab02677c
Author: Ceki Gulcu <ceki at 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.


More information about the logback-dev mailing list