[logback-dev] svn commit: r2349 - in logback/trunk/logback-classic/src: main/java/ch/qos/logback/classic main/java/ch/qos/logback/classic/turbo test/input/turbo test/java/ch/qos/logback/classic/turbo
noreply.ceki at qos.ch
noreply.ceki at qos.ch
Wed Jul 15 10:54:52 CEST 2009
Author: ceki
Date: Wed Jul 15 10:54:51 2009
New Revision: 2349
Modified:
logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java
logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java
logback/trunk/logback-classic/src/test/input/turbo/scan1.xml
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java
Log:
- Tested version of ReconfigureOnChnage. Related to LBCORE-59
Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java
==============================================================================
--- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java (original)
+++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java Wed Jul 15 10:54:51 2009
@@ -66,6 +66,8 @@
boolean started = false;
+ int resetCount = 0;
+
public LoggerContext() {
super();
this.loggerCache = new Hashtable<String, Logger>();
@@ -207,6 +209,7 @@
*/
@Override
public void reset() {
+ resetCount++;
super.reset();
root.recursiveReset();
resetTurboFilterList();
@@ -347,5 +350,10 @@
public void setMaxCallerDataDepth(int maxCallerDataDepth) {
this.maxCallerDataDepth = maxCallerDataDepth;
}
+
+ @Override
+ public String getName() {
+ return "resetCount="+resetCount;
+ }
}
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 Wed Jul 15 10:54:51 2009
@@ -30,6 +30,9 @@
*/
public class ReconfigureOnChangeFilter extends TurboFilter {
+ final static long INIT = System.currentTimeMillis();
+ final static long SENTINEL = Long.MAX_VALUE;
+
final static long DEFAULT_REFRESH_PERIOD = 60 * 1000; // 1 minute
long refreshPeriod = DEFAULT_REFRESH_PERIOD;
File fileToScan;
@@ -43,15 +46,17 @@
if (url != null) {
fileToScan = convertToFile(url);
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());
+ synchronized (context) {
+ long inSeconds = refreshPeriod / 1000;
+ addInfo("Will scan for changes in file [" + fileToScan + "] every "
+ + inSeconds + " seconds. "+stem());
+ lastModified = fileToScan.lastModified();
+ updateNextCheck(System.currentTimeMillis());
+ }
super.start();
}
} else {
- addError("Could not find URL of file to scan. Thread "+currentThreadName());
+ addError("Could not find URL of file to scan.");
}
}
@@ -86,11 +91,15 @@
return FilterReply.NEUTRAL;
}
- boolean changed = changeDetected();
- if (changed) {
- addInfo("[" + fileToScan + "] change detected. Reconfiguring "+currentThreadName());
- addInfo("Resetting and reconfiguring context [" + context.getName() + "]");
- reconfigure();
+ synchronized (context) {
+ boolean changed = changeDetected();
+ if (changed) {
+ addInfo("[" + fileToScan + "] change detected. Reconfiguring. "+stem());
+
+ addInfo("Resetting and reconfiguring context [" + context.getName()
+ + "]");
+ reconfigure();
+ }
}
return FilterReply.NEUTRAL;
}
@@ -99,12 +108,17 @@
nextCheck = now + refreshPeriod;
}
+ String stem() {
+ return currentThreadName() + ", context " + context.getName()
+ + ", nextCheck=" + (nextCheck - INIT);
+ }
+
// This method is synchronized to prevent near-simultaneous re-configurations
- protected synchronized boolean changeDetected() {
+ protected boolean changeDetected() {
long now = System.currentTimeMillis();
if (now >= nextCheck) {
updateNextCheck(now);
- return (lastModified != fileToScan.lastModified());
+ return (lastModified != fileToScan.lastModified() && lastModified != SENTINEL);
}
return false;
}
@@ -112,7 +126,19 @@
String currentThreadName() {
return Thread.currentThread().getName();
}
+
+ void disableSubsequentRecofiguration() {
+ lastModified = SENTINEL;
+ }
+
protected void reconfigure() {
+ // Even though this method resets 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 thread if it was already
+ // executing when the context was reset.
+ // We prevent multiple reconfigurations (for the same file change event) by
+ // setting an appropriate sentinel value for lastMofidied field.
+ disableSubsequentRecofiguration();
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(context);
LoggerContext lc = (LoggerContext) context;
Modified: logback/trunk/logback-classic/src/test/input/turbo/scan1.xml
==============================================================================
--- logback/trunk/logback-classic/src/test/input/turbo/scan1.xml (original)
+++ logback/trunk/logback-classic/src/test/input/turbo/scan1.xml Wed Jul 15 10:54:51 2009
@@ -1,7 +1,7 @@
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE configuration>
-<configuration scan="true" scanPeriod="1 millisecond">
+<configuration scan="true" scanPeriod="10 millisecond">
<root level="ERROR"/>
</configuration>
\ No newline at end of file
Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java (original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java Wed Jul 15 10:54:51 2009
@@ -1,6 +1,5 @@
package ch.qos.logback.classic.turbo;
-import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertTrue;
import java.io.File;
@@ -13,7 +12,6 @@
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;
@@ -23,13 +21,15 @@
public class ReconfigureOnChangeTest {
LoggerContext loggerContext = new LoggerContext();
Logger logger = loggerContext.getLogger(this.getClass());
- final static int THREAD_COUNT = 3;
+ final static int THREAD_COUNT = 5;
+
+ static int TOTAL_TEST_DURATION = 2000;
+ // it actually takes time for Windows to propagate file modification changes
+ // values below 100 milliseconds can be problematic
+ static int SLEEP_BETWEEN_UPDATES = 300;
- 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);
@@ -57,36 +57,38 @@
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);
-
+ assertTrue(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()) {
+ if (isDone()) {
return;
}
counter++;
configFile.setLastModified(System.currentTimeMillis());
}
}
-
}
}
More information about the logback-dev
mailing list