[logback-dev] svn commit: r2328 - in logback/trunk/logback-core/src: main/java/ch/qos/logback/core main/java/ch/qos/logback/core/rolling main/java/ch/qos/logback/core/rolling/helper test/java/ch/qos/logback/core/contention test/java/ch/qos/logback/core/rolling test/java/ch/qos/logback/core/status

noreply.ceki at qos.ch noreply.ceki at qos.ch
Wed Jul 8 15:02:33 CEST 2009


Author: ceki
Date: Wed Jul  8 15:02:33 2009
New Revision: 2328

Added:
   logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/MultiThreadedHarness.java
   logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/MultiThreadedRollingTest.java
Modified:
   logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java
   logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java
   logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java
   logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java
   logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java
   logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java
   logback/trunk/logback-core/src/test/java/ch/qos/logback/core/status/StatusChecker.java

Log:
Working on thread safety of RollingAppender, related to LBCLASSIC-142
 	 

Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java
==============================================================================
--- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java	(original)
+++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java	Wed Jul  8 15:02:33 2009
@@ -22,8 +22,8 @@
 /**
  * FileAppender appends log events to a file.
  * 
- * For more informatio about this appender, please refer to the online manual at
- * http://logback.qos.ch/manual/appenders.html#FileAppender
+ * For more information about this appender, please refer to the online manual
+ * at http://logback.qos.ch/manual/appenders.html#FileAppender
  * 
  * @author Ceki Gülcü
  */
@@ -66,13 +66,13 @@
    * the file to append to.
    */
   public void setFile(String file) {
-    if(file == null) {
+    if (file == null) {
       fileName = file;
     } else {
       // Trim spaces from both ends. The users probably does not want
       // trailing spaces in file names.
       String val = file.trim();
-      fileName = val;      
+      fileName = val;
     }
   }
 
@@ -90,7 +90,6 @@
     return append;
   }
 
-  
   /**
    * This method is used by derived classes to obtain the raw file property.
    * Regular users should not be calling this method.

Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java
==============================================================================
--- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java	(original)
+++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java	Wed Jul  8 15:02:33 2009
@@ -52,13 +52,13 @@
       addError("For more information, please visit http://logback.qos.ch/codes.html#rfa_no_rp");
       return;
     }
-    
-    if(isPrudent()) {
-      if(rawFileProperty() !=  null) {
+
+    if (isPrudent()) {
+      if (rawFileProperty() != null) {
         addWarn("Setting \"File\" property to null on account of prudent mode");
-        setFile(null);    
+        setFile(null);
       }
-      if(rollingPolicy.getCompressionMode() != CompressionMode.NONE) {
+      if (rollingPolicy.getCompressionMode() != CompressionMode.NONE) {
         addError("Compression is not supported in prudent mode. Aborting");
         return;
       }
@@ -73,14 +73,13 @@
   public void setFile(String file) {
     // http://jira.qos.ch/browse/LBCORE-94
     // allow setting the file name to null if mandated by prudent mode
-    if(file != null && ((triggeringPolicy != null) || (rollingPolicy != null))) {
+    if (file != null && ((triggeringPolicy != null) || (rollingPolicy != null))) {
       addError("File property must be set before any triggeringPolicy or rollingPolicy properties");
       addError("Visit http://logback.qos.ch/codes.html#rfa_file_after for more information");
     }
     super.setFile(file);
   }
 
-  
   @Override
   public String getFile() {
     return rollingPolicy.getActiveFileName();
@@ -131,8 +130,10 @@
   protected void subAppend(E event) {
     // The roll-over check must precede actual writing. This is the
     // only correct behavior for time driven triggers.
-    if (triggeringPolicy.isTriggeringEvent(activeFile, event)) {
-      rollover();
+    synchronized (triggeringPolicy) {
+      if (triggeringPolicy.isTriggeringEvent(activeFile, event)) {
+        rollover();
+      }
     }
 
     super.subAppend(event);

Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java
==============================================================================
--- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java	(original)
+++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java	Wed Jul  8 15:02:33 2009
@@ -1,16 +1,24 @@
+/**
+ * Logback: the generic, reliable, fast and flexible logging framework.
+ * 
+ * Copyright (C) 2000-2009, QOS.ch
+ * 
+ * This library is free software, you can redistribute it and/or modify it under
+ * the terms of the GNU Lesser General Public License as published by the Free
+ * Software Foundation.
+ */
 package ch.qos.logback.core.rolling.helper;
 
 public enum PeriodicityType {
 
-  ERRONEOUS, TOP_OF_SECOND, TOP_OF_MINUTE, TOP_OF_HOUR, HALF_DAY, TOP_OF_DAY, TOP_OF_WEEK, TOP_OF_MONTH;
+  ERRONEOUS, TOP_OF_MILLISECOND, TOP_OF_SECOND, TOP_OF_MINUTE, TOP_OF_HOUR, HALF_DAY, TOP_OF_DAY, TOP_OF_WEEK, TOP_OF_MONTH;
 
-  // The followed list is assued to be in 
+  // The followed list consists of valid periodicy types in increasing period
+  // lengths
   static PeriodicityType[] VALID_ORDERED_LIST = new PeriodicityType[] {
-      PeriodicityType.TOP_OF_SECOND, 
-      PeriodicityType.TOP_OF_MINUTE,
-      PeriodicityType.TOP_OF_HOUR, 
-      PeriodicityType.TOP_OF_DAY, 
-      PeriodicityType.TOP_OF_WEEK,
+      TOP_OF_MILLISECOND, PeriodicityType.TOP_OF_SECOND,
+      PeriodicityType.TOP_OF_MINUTE, PeriodicityType.TOP_OF_HOUR,
+      PeriodicityType.TOP_OF_DAY, PeriodicityType.TOP_OF_WEEK,
       PeriodicityType.TOP_OF_MONTH };
 
 }

Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java
==============================================================================
--- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java	(original)
+++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java	Wed Jul  8 15:02:33 2009
@@ -75,7 +75,8 @@
     if (datePattern != null) {
       for (PeriodicityType i : PeriodicityType.VALID_ORDERED_LIST) {
         SimpleDateFormat simpleDateFormat = new SimpleDateFormat(datePattern);
-        simpleDateFormat.setTimeZone(GMT_TIMEZONE); // all date formatting done in GMT
+        simpleDateFormat.setTimeZone(GMT_TIMEZONE); // all date formatting done
+        // in GMT
 
         String r0 = simpleDateFormat.format(epoch);
         rollingCalendar.setType(i);
@@ -90,44 +91,41 @@
       }
     }
     // we failed
-    return PeriodicityType.ERRONEOUS; 
+    return PeriodicityType.ERRONEOUS;
   }
 
   public void printPeriodicity(ContextAwareBase cab) {
     switch (type) {
+    case TOP_OF_MILLISECOND:
+      cab.addInfo("Roll-over every millisecond.");
+      break;
+
     case TOP_OF_SECOND:
       cab.addInfo("Roll-over every second.");
-
       break;
 
     case TOP_OF_MINUTE:
       cab.addInfo("Roll-over every minute.");
-
       break;
 
     case TOP_OF_HOUR:
       cab.addInfo("Roll-over at the top of every hour.");
-
       break;
 
     case HALF_DAY:
       cab.addInfo("Roll-over at midday and midnight.");
-
       break;
 
     case TOP_OF_DAY:
       cab.addInfo("Roll-over at midnight.");
-
       break;
 
     case TOP_OF_WEEK:
       cab.addInfo("Rollover at the start of week.");
-
       break;
 
     case TOP_OF_MONTH:
       cab.addInfo("Rollover at start of every month.");
-
       break;
 
     default:
@@ -139,17 +137,19 @@
     this.setTime(now);
 
     switch (type) {
+    case TOP_OF_MILLISECOND:
+      this.add(Calendar.MILLISECOND, periods);
+      break;
+
     case TOP_OF_SECOND:
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.SECOND, periods);
-
       break;
 
     case TOP_OF_MINUTE:
       this.set(Calendar.SECOND, 0);
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.MINUTE, periods);
-
       break;
 
     case TOP_OF_HOUR:
@@ -157,7 +157,6 @@
       this.set(Calendar.SECOND, 0);
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.HOUR_OF_DAY, periods);
-
       break;
 
     case TOP_OF_DAY:
@@ -166,7 +165,6 @@
       this.set(Calendar.SECOND, 0);
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.DATE, periods);
-
       break;
 
     case TOP_OF_WEEK:
@@ -176,7 +174,6 @@
       this.set(Calendar.SECOND, 0);
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.WEEK_OF_YEAR, periods);
-
       break;
 
     case TOP_OF_MONTH:
@@ -186,7 +183,6 @@
       this.set(Calendar.SECOND, 0);
       this.set(Calendar.MILLISECOND, 0);
       this.add(Calendar.MONTH, periods);
-
       break;
 
     default:
@@ -195,7 +191,7 @@
 
     return getTime();
   }
-  
+
   public Date getNextTriggeringDate(Date now) {
     return getRelativeDate(now, 1);
   }

Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/MultiThreadedHarness.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/MultiThreadedHarness.java	Wed Jul  8 15:02:33 2009
@@ -0,0 +1,65 @@
+/**
+ * Logback: the generic, reliable, fast and flexible logging framework.
+ * 
+ * Copyright (C) 2000-2009, QOS.ch
+ * 
+ * This library is free software, you can redistribute it and/or modify it under
+ * the terms of the GNU Lesser General Public License as published by the Free
+ * Software Foundation.
+ */
+package ch.qos.logback.core.contention;
+
+
+/**
+ * Useful scaffolding/harness to start and stop multiple threads.
+ * 
+ * @author Joern Huxhorn
+ * @author Ralph Goers
+ * @author Ceki Gulcu
+ */
+public class MultiThreadedHarness {
+
+  RunnableWithCounterAndDone[] runnableArray;
+  Thread[] threadArray;
+  final long overallDurationInMillis;
+
+  public MultiThreadedHarness(long overallDurationInMillis) {
+    this.overallDurationInMillis = overallDurationInMillis;
+  }
+
+  public void printEnvironmentInfo(String msg) {
+    System.out.println("=== " + msg + " ===");
+    System.out.println("java.runtime.version = "
+        + System.getProperty("java.runtime.version"));
+    System.out.println("java.vendor          = "
+        + System.getProperty("java.vendor"));
+    System.out.println("java.version         = "
+        + System.getProperty("java.version"));
+    System.out.println("os.name              = "
+        + System.getProperty("os.name"));
+    System.out.println("os.version           = "
+        + System.getProperty("os.version"));
+  }
+
+  public void execute(RunnableWithCounterAndDone[] runnableArray)
+      throws InterruptedException {
+    this.runnableArray = runnableArray;
+    Thread[] threadArray = new Thread[runnableArray.length];
+
+    for (int i = 0; i < runnableArray.length; i++) {
+      threadArray[i] = new Thread(runnableArray[i]);
+    }
+    for (Thread t : threadArray) {
+      t.start();
+    }
+    // let the threads run for a while
+    Thread.sleep(overallDurationInMillis);
+
+    for (RunnableWithCounterAndDone r : runnableArray) {
+      r.setDone(true);
+    }
+    for (Thread t : threadArray) {
+      t.join();
+    }
+  }
+}

Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java
==============================================================================
--- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java	(original)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java	Wed Jul  8 15:02:33 2009
@@ -1,8 +1,16 @@
+/**
+ * Logback: the generic, reliable, fast and flexible logging framework.
+ * 
+ * Copyright (C) 2000-2009, QOS.ch
+ * 
+ * This library is free software, you can redistribute it and/or modify it under
+ * the terms of the GNU Lesser General Public License as published by the Free
+ * Software Foundation.
+ */
 package ch.qos.logback.core.contention;
 
 
 /**
- * 
  * Useful scaffolding to measure the throughput of certain operations when
  * invoked by multiple threads.
  * 
@@ -10,51 +18,13 @@
  * @author Ralph Goers
  * @author Ceki Gulcu
  */
-public class ThreadedThroughputCalculator {
+public class ThreadedThroughputCalculator extends MultiThreadedHarness {
 
-  RunnableWithCounterAndDone[] runnableArray;
-  Thread[] threadArray;
-  final long overallDurationInMillis;
 
   public ThreadedThroughputCalculator(long overallDurationInMillis) {
-    this.overallDurationInMillis = overallDurationInMillis;
-  }
-
-  public void printEnvironmentInfo(String msg) {
-    System.out.println("=== " + msg + " ===");
-    System.out.println("java.runtime.version = "
-        + System.getProperty("java.runtime.version"));
-    System.out.println("java.vendor          = "
-        + System.getProperty("java.vendor"));
-    System.out.println("java.version         = "
-        + System.getProperty("java.version"));
-    System.out.println("os.name              = "
-        + System.getProperty("os.name"));
-    System.out.println("os.version           = "
-        + System.getProperty("os.version"));
+    super(overallDurationInMillis);
   }
 
-  public void execute(RunnableWithCounterAndDone[] runnableArray)
-      throws InterruptedException {
-    this.runnableArray = runnableArray;
-    Thread[] threadArray = new Thread[runnableArray.length];
-
-    for (int i = 0; i < runnableArray.length; i++) {
-      threadArray[i] = new Thread(runnableArray[i]);
-    }
-    for (Thread t : threadArray) {
-      t.start();
-    }
-    // let the threads run for a while
-    Thread.sleep(overallDurationInMillis);
-
-    for (RunnableWithCounterAndDone r : runnableArray) {
-      r.setDone(true);
-    }
-    for (Thread t : threadArray) {
-      t.join();
-    }
-  }
   public void printThroughput(String msg) throws InterruptedException {
     printThroughput(msg, false);
   }

Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/MultiThreadedRollingTest.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/MultiThreadedRollingTest.java	Wed Jul  8 15:02:33 2009
@@ -0,0 +1,108 @@
+package ch.qos.logback.core.rolling;
+
+import static org.junit.Assert.fail;
+
+import java.io.File;
+
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+
+import ch.qos.logback.core.Context;
+import ch.qos.logback.core.ContextBase;
+import ch.qos.logback.core.Layout;
+import ch.qos.logback.core.contention.MultiThreadedHarness;
+import ch.qos.logback.core.contention.RunnableWithCounterAndDone;
+import ch.qos.logback.core.layout.EchoLayout;
+import ch.qos.logback.core.status.StatusChecker;
+import ch.qos.logback.core.testUtil.RandomUtil;
+import ch.qos.logback.core.util.CoreTestConstants;
+import ch.qos.logback.core.util.StatusPrinter;
+
+public class MultiThreadedRollingTest {
+
+  final static int NUM_THREADS = 5;
+  final static int TOTAL_DURATION = 2000;
+  
+  Layout<Object> layout;
+  Context context = new ContextBase();
+
+  int diff = RandomUtil.getPositiveInt();
+  String outputDirStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "multi-" + diff
+      + "/";
+
+  RollingFileAppender<Object> rfa = new RollingFileAppender<Object>();
+
+  @Before
+  public void setUp() throws Exception {
+    layout = new EchoLayout<Object>();
+    File outputDir = new File(outputDirStr);
+    outputDir.mkdirs();
+    
+    rfa.setName("rolling");
+    rfa.setLayout(layout);
+    rfa.setContext(context);
+    rfa.setFile(outputDirStr + "output.log");
+    String datePattern = "yyyy-MM-dd'T'HH_mm_ss_SSS";
+
+    TimeBasedRollingPolicy tbrp = new TimeBasedRollingPolicy();
+    tbrp.setFileNamePattern(outputDirStr + "test-%d{" + datePattern + "}");
+    tbrp.setContext(context);
+    tbrp.setParent(rfa);
+    tbrp.start();
+
+    rfa.setRollingPolicy(tbrp);
+    rfa.start();
+  }
+
+  @After
+  public void tearDown() throws Exception {
+    rfa.stop();
+  }
+  
+  RunnableWithCounterAndDone[] buildRunnableArray() {
+    RunnableWithCounterAndDone[] runnableArray = new RunnableWithCounterAndDone[NUM_THREADS];
+    for (int i = 0; i < NUM_THREADS; i++) {
+      runnableArray[i] = new RFARunnable(i, rfa);
+    }
+    return runnableArray;
+  }
+
+  @Test
+  public void executeHarness() throws InterruptedException {
+    MultiThreadedHarness multiThreadedHarness = new MultiThreadedHarness(TOTAL_DURATION);
+    RunnableWithCounterAndDone[] runnableArray = buildRunnableArray();
+    multiThreadedHarness.execute(runnableArray);
+    StatusPrinter.print(context);
+    
+    StatusChecker checker = new StatusChecker(context.getStatusManager());
+    if(!checker.isErrorFree()) {
+      fail("errors reported");
+      StatusPrinter.print(context);
+    }
+    
+  }
+
+  long diff(long start) {
+    return System.currentTimeMillis() - start;
+  }
+
+  static class RFARunnable extends RunnableWithCounterAndDone {
+    RollingFileAppender<Object> rfa;
+    int id;
+    RFARunnable(int id, RollingFileAppender<Object> rfa) {
+      this.id = id;
+      this.rfa = rfa;
+    }
+
+    public void run() {
+      while (!isDone()) {
+        counter++;
+        rfa.doAppend(id + " " + counter);
+      }
+      System.out.println("id="+id + ", counter="+counter + " on exit");
+    }
+    
+  }
+
+}

Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java
==============================================================================
--- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java	(original)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java	Wed Jul  8 15:02:33 2009
@@ -5,7 +5,7 @@
 
 @RunWith(Suite.class)
 @Suite.SuiteClasses( { RenamingTest.class, SizeBasedRollingTest.class,
-    TimeBasedRollingTest.class,
+    TimeBasedRollingTest.class, TimeBasedRollingWithCleanTest.class,
     ch.qos.logback.core.rolling.helper.PackageTest.class })
 public class PackageTest {
 }

Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/status/StatusChecker.java
==============================================================================
--- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/status/StatusChecker.java	(original)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/status/StatusChecker.java	Wed Jul  8 15:02:33 2009
@@ -24,6 +24,11 @@
     this.sm = sm;
   }
 
+  public boolean isErrorFree() {
+    int level = sm.getLevel();
+    return level < Status.ERROR;
+  }
+  
   public boolean containsMatch(int level, String regex) {
     Pattern p = Pattern.compile(regex);
 


More information about the logback-dev mailing list