[logback-dev] svn commit: r2348 - in logback/trunk: logback-classic/src/main/java/ch/qos/logback/classic/turbo logback-classic/src/test/input/turbo logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135 logback-classic/src/test/java/ch/qos/logback/classic/joran logback-classic/src/test/java/ch/qos/logback/classic/turbo logback-core/src/test/java/ch/qos/logback/core/contention logback-core/src/test/java/ch/qos/logback/core/status
noreply.ceki at qos.ch
noreply.ceki at qos.ch
Tue Jul 14 22:47:17 CEST 2009
Author: ceki
Date: Tue Jul 14 22:47:17 2009
New Revision: 2348
Added:
logback/trunk/logback-classic/src/test/input/turbo/
logback/trunk/logback-classic/src/test/input/turbo/scan1.xml
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java
Modified:
logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java
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/status/StatusChecker.java
Log:
- testing auto reconfiguration in a multi-threaded environment. Related to LBCORE-59
Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java
==============================================================================
--- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java (original)
+++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java Tue Jul 14 22:47:17 2009
@@ -25,66 +25,71 @@
/**
* Reconfigure a LoggerContext when the configuration file changes.
*
- * @author Ceki Gulcu
- *
- * */
+ * @author Ceki Gulcu
+ *
+ */
public class ReconfigureOnChangeFilter extends TurboFilter {
- final static long DEFAULT_REFRESH_PERIOD = 60*1000; // 1 minute
+ final static long DEFAULT_REFRESH_PERIOD = 60 * 1000; // 1 minute
long refreshPeriod = DEFAULT_REFRESH_PERIOD;
File fileToScan;
protected long nextCheck;
long lastModified;
-
@Override
public void start() {
- URL url = (URL) context.getObject(CoreConstants.URL_OF_LAST_CONFIGURATION_VIA_JORAN);
- if(url != null) {
+ URL url = (URL) context
+ .getObject(CoreConstants.URL_OF_LAST_CONFIGURATION_VIA_JORAN);
+ if (url != null) {
fileToScan = convertToFile(url);
- if(fileToScan != null) {
- long inSeconds = refreshPeriod/1000;
- addInfo("Will scan for changes in file ["+fileToScan+"] every "+inSeconds+" seconds");
+ if (fileToScan != null) {
+ long inSeconds = refreshPeriod / 1000;
+ addInfo("Will scan for changes in file [" + fileToScan + "] every "
+ + inSeconds + " seconds"+ " Thread "+currentThreadName());
lastModified = fileToScan.lastModified();
updateNextCheck(System.currentTimeMillis());
super.start();
}
} else {
- addError("Could not find URL of file to scan.");
+ addError("Could not find URL of file to scan. Thread "+currentThreadName());
}
}
-
+
File convertToFile(URL url) {
String protocol = url.getProtocol();
- if("file".equals(protocol)) {
+ if ("file".equals(protocol)) {
File file = new File(url.getFile());
return file;
} else {
- addError("URL ["+url+"] is not of type file");
+ addError("URL [" + url + "] is not of type file");
return null;
}
}
-
+
// a counter of the number of time the decide method is called
- private volatile int invocationCounter = 0;
-
+ // 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.
+
+ private int invocationCounter = 0;
+
@Override
- public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
- if(!isStarted()) {
+ public FilterReply decide(Marker marker, Logger logger, Level level,
+ String format, Object[] params, Throwable t) {
+ if (!isStarted()) {
return FilterReply.NEUTRAL;
}
-
- System.out.println("counter="+invocationCounter+", format="+format);
+
// for performance reasons, check for changes every 16 invocations
- if(((invocationCounter++) & 0xF) != 0xF) {
+ if (((invocationCounter++) & 0xF) != 0xF) {
return FilterReply.NEUTRAL;
}
-
boolean changed = changeDetected();
- if(changed) {
- addInfo("["+fileToScan + "] change detected. Reconfiguring");
- addInfo("Resetting and reconfiguring context ["+context.getName()+"]");
+ if (changed) {
+ addInfo("[" + fileToScan + "] change detected. Reconfiguring "+currentThreadName());
+ addInfo("Resetting and reconfiguring context [" + context.getName() + "]");
reconfigure();
}
return FilterReply.NEUTRAL;
@@ -93,17 +98,20 @@
void updateNextCheck(long now) {
nextCheck = now + refreshPeriod;
}
-
- protected boolean changeDetected() {
+
+ // This method is synchronized to prevent near-simultaneous re-configurations
+ protected synchronized boolean changeDetected() {
long now = System.currentTimeMillis();
- if(now >= nextCheck) {
+ if (now >= nextCheck) {
updateNextCheck(now);
return (lastModified != fileToScan.lastModified());
}
return false;
}
-
-
+
+ String currentThreadName() {
+ return Thread.currentThread().getName();
+ }
protected void reconfigure() {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(context);
@@ -113,7 +121,7 @@
jc.doConfigure(fileToScan);
} catch (JoranException e) {
addError("Failure during reconfiguration", e);
- }
+ }
}
public long getRefreshPeriod() {
Added: logback/trunk/logback-classic/src/test/input/turbo/scan1.xml
==============================================================================
--- (empty file)
+++ logback/trunk/logback-classic/src/test/input/turbo/scan1.xml Tue Jul 14 22:47:17 2009
@@ -0,0 +1,7 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<!DOCTYPE configuration>
+
+<configuration scan="true" scanPeriod="1 millisecond">
+ <root level="ERROR"/>
+</configuration>
+
\ No newline at end of file
Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java (original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java Tue Jul 14 22:47:17 2009
@@ -16,7 +16,7 @@
Logger logger;
- LoggingRunnable(Logger logger) {
+ public LoggingRunnable(Logger logger) {
this.logger = logger;
}
Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java (original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java Tue Jul 14 22:47:17 2009
@@ -248,6 +248,7 @@
assertEquals("hello user2", le.getMessage());
}
+ // Tests whether ConfigurationAction is installing ReconfigureOnChangeFilter
@Test
public void scan1() throws JoranException, IOException, InterruptedException {
@@ -267,6 +268,5 @@
assertTrue(checker.isErrorFree());
assertTrue(checker.containsMatch("Resetting and reconfiguring context"));
StatusPrinter.print(loggerContext);
-
}
}
Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java Tue Jul 14 22:47:17 2009
@@ -0,0 +1,92 @@
+package ch.qos.logback.classic.turbo;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+
+import java.io.File;
+import java.io.IOException;
+
+import org.junit.Test;
+
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.issue.lbclassic135.LoggingRunnable;
+import ch.qos.logback.classic.joran.JoranConfigurator;
+import ch.qos.logback.classic.util.TeztConstants;
+
+import ch.qos.logback.core.contention.MultiThreadedHarness;
+import ch.qos.logback.core.contention.RunnableWithCounterAndDone;
+import ch.qos.logback.core.joran.spi.JoranException;
+import ch.qos.logback.core.status.StatusChecker;
+import ch.qos.logback.core.util.StatusPrinter;
+
+public class ReconfigureOnChangeTest {
+ LoggerContext loggerContext = new LoggerContext();
+ Logger logger = loggerContext.getLogger(this.getClass());
+ final static int THREAD_COUNT = 3;
+
+ static int TOTAL_TEST_DURATION = 10000;
+ static int SLEEP_BETWEEN_UPDATES = 1000;
+
+ MultiThreadedHarness harness = new MultiThreadedHarness(TOTAL_TEST_DURATION);
+
+ void configure(String file) throws JoranException {
+ JoranConfigurator jc = new JoranConfigurator();
+ jc.setContext(loggerContext);
+ jc.doConfigure(file);
+ }
+
+ RunnableWithCounterAndDone[] buildRunnableArray(File configFile) {
+
+ RunnableWithCounterAndDone[] rArray = new RunnableWithCounterAndDone[THREAD_COUNT];
+ rArray[0] = new Updater(configFile);
+ for (int i = 1; i < THREAD_COUNT; i++) {
+ rArray[i] = new LoggingRunnable(logger);
+ }
+ return rArray;
+ }
+
+ // Tests whether ConfigurationAction is installing ReconfigureOnChangeFilter
+ @Test
+ public void scan1() throws JoranException, IOException, InterruptedException {
+
+ String configFileAsStr = TeztConstants.TEST_DIR_PREFIX
+ + "input/turbo/scan1.xml";
+ configure(configFileAsStr);
+
+ File file = new File(configFileAsStr);
+ RunnableWithCounterAndDone[] runnableArray = buildRunnableArray(file);
+ harness.execute(runnableArray);
+
+ long expectedRreconfigurations = runnableArray[0].getCounter();
+
+ StatusChecker checker = new StatusChecker(loggerContext);
+ StatusPrinter.print(loggerContext);
+ assertTrue(checker.isErrorFree());
+ int result = checker.matchCount("Resetting and reconfiguring context");
+ assertEquals(expectedRreconfigurations, result);
+
+ }
+
+ class Updater extends RunnableWithCounterAndDone {
+ File configFile;
+ Updater(File configFile) {
+ this.configFile = configFile;
+ }
+ public void run() {
+ while (!isDone()) {
+ try {
+ Thread.sleep(SLEEP_BETWEEN_UPDATES);
+ } catch (InterruptedException e) {
+ }
+ if(isDone()) {
+ return;
+ }
+ counter++;
+ configFile.setLastModified(System.currentTimeMillis());
+ }
+ }
+
+ }
+
+}
Modified: 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/contention/MultiThreadedHarness.java (original)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/MultiThreadedHarness.java Tue Jul 14 22:47:17 2009
@@ -47,7 +47,7 @@
Thread[] threadArray = new Thread[runnableArray.length];
for (int i = 0; i < runnableArray.length; i++) {
- threadArray[i] = new Thread(runnableArray[i]);
+ threadArray[i] = new Thread(runnableArray[i], "Harness["+i+"]");
}
for (Thread t : threadArray) {
t.start();
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 Tue Jul 14 22:47:17 2009
@@ -61,6 +61,19 @@
return false;
}
+ public int matchCount(String regex) {
+ int count = 0;
+ Pattern p = Pattern.compile(regex);
+ for(Status status: sm.getCopyOfStatusList()) {
+ String msg = status.getMessage();
+ Matcher matcher = p.matcher(msg);
+ if (matcher.lookingAt()) {
+ count++;
+ }
+ }
+ return count;
+ }
+
public boolean containsException(Class exceptionType) {
Iterator stati = sm.getCopyOfStatusList().iterator();
while (stati.hasNext()) {
More information about the logback-dev
mailing list