Author: ceki Date: Tue Jul 14 16:59:25 2009 New Revision: 2344 Added: logback/trunk/logback-classic/src/test/input/joran/scan1.xml Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/joran/action/ConfigurationAction.java 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/joran/JoranConfiguratorTest.java Log: Adding support for automatic reconfiguration. Related to LBCORE-59 This implementation checks for changes in the config file every N seconds, where N is a user specified parameter. However, as a performance twist, the check is performed every 16 logging events. It's still ongoing work Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/joran/action/ConfigurationAction.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/joran/action/ConfigurationAction.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/joran/action/ConfigurationAction.java Tue Jul 14 16:59:25 2009 @@ -1,7 +1,7 @@ /** - * LOGBack: the generic, reliable, fast and flexible logging framework. + * Logback: the generic, reliable, fast and flexible logging framework. * - * Copyright (C) 1999-2006, QOS.ch + * 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 @@ -13,42 +13,73 @@ import org.xml.sax.Attributes; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter; import ch.qos.logback.core.joran.action.Action; import ch.qos.logback.core.joran.spi.InterpretationContext; +import ch.qos.logback.core.util.Duration; +import ch.qos.logback.core.util.OptionHelper; import ch.qos.logback.core.util.StatusPrinter; - - public class ConfigurationAction extends Action { static final String INTERNAL_DEBUG_ATTR = "debug"; + static final String SCAN_ATTR = "scan"; + static final String SCAN_PERIOD_ATTR = "scanPeriod"; + boolean debugMode = false; public void begin(InterpretationContext ec, String name, Attributes attributes) { String debugAttrib = attributes.getValue(INTERNAL_DEBUG_ATTR); - if ( - (debugAttrib == null) || debugAttrib.equals("") - || debugAttrib.equals("false") || debugAttrib.equals("null")) { + if (OptionHelper.isEmpty(debugAttrib) + || debugAttrib.equalsIgnoreCase("false") + || debugAttrib.equalsIgnoreCase("null")) { addInfo(INTERNAL_DEBUG_ATTR + " attribute not set"); } else { - //LoggerContext loggerContext = (LoggerContext) context; - //ConfiguratorBase.attachTemporaryConsoleAppender(context); - + // LoggerContext loggerContext = (LoggerContext) context; + // ConfiguratorBase.attachTemporaryConsoleAppender(context); + debugMode = true; } - - // the context is turbo filter attachable, so it is pushed on top of the stack + + processScanAttrib(attributes); + + // the context is turbo filter attachable, so it is pushed on top of the + // stack ec.pushObject(getContext()); } + void processScanAttrib(Attributes attributes) { + String scanAttrib = attributes.getValue(SCAN_ATTR); + if (!OptionHelper.isEmpty(scanAttrib) + && !"false".equalsIgnoreCase(scanAttrib)) { + ReconfigureOnChangeFilter rocf = new ReconfigureOnChangeFilter(); + rocf.setContext(context); + String scanPeriodAttrib = attributes.getValue(SCAN_PERIOD_ATTR); + if (!OptionHelper.isEmpty(scanPeriodAttrib)) { + try { + Duration duration = Duration.valueOf(scanPeriodAttrib); + rocf.setRefreshPeriod(duration.getMilliseconds()); + addInfo("Setting ReconfigureOnChangeFilter scanning period to " + + duration); + } catch (NumberFormatException nfe) { + addError("Error while converting [" + scanAttrib + "] to long", nfe); + } + } + rocf.start(); + LoggerContext lc = (LoggerContext) context; + addInfo("Adding ReconfigureOnChangeFilter as a turbo filter"); + lc.addTurboFilter(rocf); + } + } + public void end(InterpretationContext ec, String name) { if (debugMode) { addInfo("End of configuration."); LoggerContext loggerContext = (LoggerContext) context; StatusPrinter.print(loggerContext); - - //LoggerContext loggerContext = (LoggerContext) context; - //ConfiguratorBase.detachTemporaryConsoleAppender(repository, errorList); + + // LoggerContext loggerContext = (LoggerContext) context; + // ConfiguratorBase.detachTemporaryConsoleAppender(repository, errorList); } ec.popObject(); } 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 16:59:25 2009 @@ -36,10 +36,11 @@ protected long nextCheck; long lastModified; + @Override public void start() { URL url = (URL) context.getObject(CoreConstants.URL_OF_LAST_CONFIGURATION_VIA_JORAN); - if(url == null) { + if(url != null) { fileToScan = convertToFile(url); if(fileToScan != null) { long inSeconds = refreshPeriod/1000; @@ -64,14 +65,26 @@ } } + // a counter of the number of time the decide method is called + private volatile int invocationCounter = 0; + @Override 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) { + return FilterReply.NEUTRAL; + } + + boolean changed = changeDetected(); if(changed) { + addInfo("["+fileToScan + "] change detected. Reconfiguring"); + addInfo("Resetting and reconfiguring context ["+context.getName()+"]"); reconfigure(); } return FilterReply.NEUTRAL; @@ -102,4 +115,12 @@ addError("Failure during reconfiguration", e); } } + + public long getRefreshPeriod() { + return refreshPeriod; + } + + public void setRefreshPeriod(long refreshPeriod) { + this.refreshPeriod = refreshPeriod; + } } Added: logback/trunk/logback-classic/src/test/input/joran/scan1.xml ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/input/joran/scan1.xml Tue Jul 14 16:59:25 2009 @@ -0,0 +1,17 @@ +<?xml version="1.0" encoding="UTF-8" ?> +<!DOCTYPE configuration> + +<configuration scan="true" scanPeriod="1 millisecond"> + + <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> + <layout class="ch.qos.logback.classic.PatternLayout"> + <Pattern>yx %d - %m%n"</Pattern> + </layout> + </appender> + + <root level="TRACE"> + <appender-ref ref="CONSOLE" /> + </root> + +</configuration> + \ No newline at end of file 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 16:59:25 2009 @@ -13,6 +13,9 @@ import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertTrue; +import java.io.File; +import java.io.IOException; + import org.junit.Test; import org.slf4j.MDC; @@ -27,7 +30,9 @@ import ch.qos.logback.core.CoreConstants; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.read.ListAppender; +import ch.qos.logback.core.status.StatusChecker; import ch.qos.logback.core.testUtil.StringListAppender; +import ch.qos.logback.core.util.StatusPrinter; public class JoranConfiguratorTest { @@ -67,12 +72,14 @@ } @Test - public void testRootLoggerLevelSettingBySystemProperty() throws JoranException { + public void testRootLoggerLevelSettingBySystemProperty() + throws JoranException { String propertyName = "logback.level"; - + System.setProperty(propertyName, "INFO"); - configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/rootLevelByProperty.xml"); - //StatusPrinter.print(loggerContext); + configure(TeztConstants.TEST_DIR_PREFIX + + "input/joran/rootLevelByProperty.xml"); + // StatusPrinter.print(loggerContext); ListAppender listAppender = (ListAppender) root.getAppender("LIST"); assertEquals(0, listAppender.list.size()); String msg = "hello world"; @@ -80,14 +87,15 @@ assertEquals(0, listAppender.list.size()); System.clearProperty(propertyName); } - + @Test public void testLoggerLevelSettingBySystemProperty() throws JoranException { String propertyName = "logback.level"; - + System.setProperty(propertyName, "DEBUG"); - configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/loggerLevelByProperty.xml"); - //StatusPrinter.print(loggerContext); + configure(TeztConstants.TEST_DIR_PREFIX + + "input/joran/loggerLevelByProperty.xml"); + // StatusPrinter.print(loggerContext); ListAppender listAppender = (ListAppender) root.getAppender("LIST"); assertEquals(0, listAppender.list.size()); String msg = "hello world"; @@ -95,11 +103,11 @@ assertEquals(1, listAppender.list.size()); System.clearProperty(propertyName); } - + @Test public void testStatusListener() throws JoranException { configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/statusListener.xml"); - //StatusPrinter.print(loggerContext); + // StatusPrinter.print(loggerContext); } @Test @@ -108,7 +116,7 @@ configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/contextRename.xml"); assertEquals("wombat", loggerContext.getName()); } - + @Test public void testEval() throws JoranException { configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/callerData.xml"); @@ -122,7 +130,7 @@ assertNotNull(slAppender); assertEquals(2, slAppender.strList.size()); assertTrue(slAppender.strList.get(0).contains(" DEBUG - toto")); - + String str1 = slAppender.strList.get(1); assertTrue(str1.contains("Caller+0")); assertTrue(str1.contains(" DEBUG - hello world")); @@ -159,7 +167,7 @@ public void testLevelFilter() throws JoranException { configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/levelFilter.xml"); - //StatusPrinter.print(loggerContext); + // StatusPrinter.print(loggerContext); logger.warn("hello"); logger.error("to be ignored"); @@ -179,7 +187,7 @@ public void testEvaluatorFilter() throws JoranException { configure(TeztConstants.TEST_DIR_PREFIX + "input/joran/evaluatorFilter.xml"); - //StatusPrinter.print(loggerContext); + // StatusPrinter.print(loggerContext); logger.warn("hello"); logger.error("to be ignored"); @@ -239,4 +247,26 @@ le = (ILoggingEvent) listAppender.list.get(1); assertEquals("hello user2", le.getMessage()); } + + @Test + public void scan1() throws JoranException, IOException, InterruptedException { + + String configFileAsStr = TeztConstants.TEST_DIR_PREFIX + + "input/joran/scan1.xml"; + configure(configFileAsStr); + + File file = new File(configFileAsStr); + file.setLastModified(System.currentTimeMillis()); + + // scanning requires 16 logs + for (int i = 0; i < 16; i++) { + logger.debug("after " + i); + } + + StatusChecker checker = new StatusChecker(loggerContext); + assertTrue(checker.isErrorFree()); + assertTrue(checker.containsMatch("Resetting and reconfiguring context")); + StatusPrinter.print(loggerContext); + + } }