Skip to content

Commit

Permalink
decouple XML at reconfiguration time
Browse files Browse the repository at this point in the history
  • Loading branch information
@ceki
ceki committed Jan 31, 2022
1 parent c2cdd08 commit c36af10
Show file tree
Hide file tree
Showing 17 changed files with 145 additions and 104 deletions.
54 changes: 28 additions & 26 deletions logback-classic/src/main/java/ch/qos/logback/classic/joran/ReconfigureOnChangeTask.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,10 +7,11 @@

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.core.CoreConstants;
import ch.qos.logback.core.joran.event.SaxEvent;
import ch.qos.logback.core.joran.spi.ConfigurationWatchList;
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil;
import ch.qos.logback.core.model.Model;
import ch.qos.logback.core.model.ModelUtil;
import ch.qos.logback.core.spi.ContextAwareBase;
import ch.qos.logback.core.status.StatusUtil;

Expand Down Expand Up @@ -48,7 +49,6 @@ public void run() {
if (!configurationWatchList.changeDetected()) {
return;
}
System.out.println("fireChangeDetected");
fireChangeDetected();
URL mainConfigurationURL = configurationWatchList.getMainURL();

Expand Down Expand Up @@ -92,57 +92,59 @@ private void performXMLConfiguration(LoggerContext lc, URL mainConfigurationURL)
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(context);
StatusUtil statusUtil = new StatusUtil(context);
List<SaxEvent> eventList = jc.recallSafeConfiguration();

Model failsafeTop = jc.recallSafeConfiguration();
URL mainURL = ConfigurationWatchListUtil.getMainWatchURL(context);
lc.reset();
long threshold = System.currentTimeMillis();
try {
jc.doConfigure(mainConfigurationURL);
if (statusUtil.hasXMLParsingErrors(threshold)) {
fallbackConfiguration(lc, eventList, mainURL);
fallbackConfiguration(lc, failsafeTop, mainURL);
}
} catch (JoranException e) {
fallbackConfiguration(lc, eventList, mainURL);
fallbackConfiguration(lc, failsafeTop, mainURL);
}
}

private List<SaxEvent> removeIncludeEvents(List<SaxEvent> unsanitizedEventList) {
List<SaxEvent> sanitizedEvents = new ArrayList<SaxEvent>();
if (unsanitizedEventList == null)
return sanitizedEvents;

for (SaxEvent e : unsanitizedEventList) {
if (!"include".equalsIgnoreCase(e.getLocalName()))
sanitizedEvents.add(e);

}
return sanitizedEvents;
}

private void fallbackConfiguration(LoggerContext lc, List<SaxEvent> eventList, URL mainURL) {
// private List<SaxEvent> removeIncludeEvents(List<SaxEvent> unsanitizedEventList) {
// List<SaxEvent> sanitizedEvents = new ArrayList<SaxEvent>();
// if (unsanitizedEventList == null)
// return sanitizedEvents;
//
// for (SaxEvent e : unsanitizedEventList) {
// if (!"include".equalsIgnoreCase(e.getLocalName()))
// sanitizedEvents.add(e);
//
// }
// return sanitizedEvents;
// }

private void fallbackConfiguration(LoggerContext lc, Model failsafeTop, URL mainURL) {
// failsafe events are used only in case of errors. Therefore, we must *not*
// invoke file inclusion since the included files may be the cause of the error.

List<SaxEvent> failsafeEvents = removeIncludeEvents(eventList);
// List<SaxEvent> failsafeEvents = removeIncludeEvents(eventList);
JoranConfigurator joranConfigurator = new JoranConfigurator();
joranConfigurator.setContext(context);
ConfigurationWatchList oldCWL = ConfigurationWatchListUtil.getConfigurationWatchList(context);
ConfigurationWatchList newCWL = oldCWL.buildClone();

if (failsafeEvents == null || failsafeEvents.isEmpty()) {
if (failsafeTop == null) {
addWarn("No previous configuration to fall back on.");
return;
} else {
addWarn(FALLING_BACK_TO_SAFE_CONFIGURATION);
addInfo("Safe model "+failsafeTop);
try {
lc.reset();
ConfigurationWatchListUtil.registerConfigurationWatchList(context, newCWL);
joranConfigurator.buildAndProcessModel(failsafeEvents);
ModelUtil.resetForReuse(failsafeTop);
joranConfigurator.processModel(failsafeTop);
addInfo(RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
joranConfigurator.registerSafeConfiguration(failsafeEvents);
joranConfigurator.registerSafeConfiguration(failsafeTop);

addInfo("after registerSafeConfiguration: " + failsafeEvents);
} catch (JoranException e) {
addInfo("after registerSafeConfiguration");
} catch (Exception e) {
addError("Unexpected exception thrown by a configuration considered safe.", e);
}
}
Expand Down
1 change: 1 addition & 0 deletions ...assic/src/main/java/ch/qos/logback/classic/model/processor/ConfigurationModelHandler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,7 @@ void processScanAttrib(ModelInterpretationContext mic, ConfigurationModel config
ReconfigureOnChangeTask rocTask = new ReconfigureOnChangeTask();
rocTask.setContext(context);

addInfo("Registering a new ReconfigureOnChangeTask "+ rocTask);
context.putObject(CoreConstants.RECONFIGURE_ON_CHANGE_TASK, rocTask);

String scanPeriodStr = mic.subst(configurationModel.getScanPeriodStr());
Expand Down
16 changes: 9 additions & 7 deletions logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil;
import ch.qos.logback.core.model.Model;
import ch.qos.logback.core.model.ModelUtil;
import ch.qos.logback.core.spi.FilterReply;
import ch.qos.logback.core.status.StatusUtil;

Expand Down Expand Up @@ -198,31 +199,32 @@ private void performXMLConfiguration(LoggerContext lc) {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(context);
StatusUtil statusUtil = new StatusUtil(context);
List<SaxEvent> saxEventList = jc.recallSafeConfiguration();
Model failSafeTop = jc.recallSafeConfiguration();
URL mainURL = ConfigurationWatchListUtil.getMainWatchURL(context);
lc.reset();
long threshold = System.currentTimeMillis();
try {
jc.doConfigure(mainConfigurationURL);
if (statusUtil.hasXMLParsingErrors(threshold)) {
fallbackConfiguration(lc, saxEventList, mainURL);
fallbackConfiguration(lc, failSafeTop, mainURL);
}
} catch (JoranException e) {
fallbackConfiguration(lc, saxEventList, mainURL);
fallbackConfiguration(lc, failSafeTop, mainURL);
}
}

private void fallbackConfiguration(LoggerContext lc, List<SaxEvent> saxEventList, URL mainURL) {
private void fallbackConfiguration(LoggerContext lc, Model failSafeTop, URL mainURL) {
JoranConfigurator joranConfigurator = new JoranConfigurator();
joranConfigurator.setContext(context);
if (saxEventList != null) {
if (failSafeTop != null) {
addWarn("Falling back to previously registered safe configuration.");
try {
lc.reset();
JoranConfigurator.informContextOfURLUsedForConfiguration(context, mainURL);
Model top = joranConfigurator.buildAndProcessModel(saxEventList);
ModelUtil.resetForReuse(failSafeTop);
joranConfigurator.processModel(failSafeTop);
addInfo("Re-registering previous fallback configuration once more as a fallback configuration point");
joranConfigurator.registerSafeConfiguration(saxEventList);
joranConfigurator.registerSafeConfiguration(failSafeTop);
} catch (Exception e) {
addError("Unexpected exception thrown by a configuration considered safe.", e);
}
Expand Down
59 changes: 39 additions & 20 deletions logback-classic/src/test/java/ch/qos/logback/classic/joran/ReconfigureOnChangeTaskTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -181,28 +181,36 @@ public void fallbackToSafe_FollowedByRecovery() throws IOException, JoranExcepti
StatusPrinter.print(loggerContext);
CountDownLatch changeDetectedLatch = waitForReconfigurationToBeDone(null);
ReconfigureOnChangeTask oldRoct = getRegisteredReconfigureTask();

addInfo("registered ReconfigureOnChangeTask ", oldRoct);
assertNotNull(oldRoct);

String badXML = "<configuration scan=\"true\" scanPeriod=\"5 millisecond\">\n" + " <root></configuration>";
writeToFile(topLevelFile, badXML);
System.out.println("Waiting for changeDetectedLatch.await()");
addInfo("Waiting for changeDetectedLatch.await()", this);
changeDetectedLatch.await();
System.out.println("Woke from changeDetectedLatch.await()");

addInfo("Woke from changeDetectedLatch.await()", this);
StatusPrinter.print(loggerContext);

try {
statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);

statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
loggerContext.getStatusManager().clear();

loggerContext.getStatusManager().clear();
addInfo("after loggerContext.getStatusManager().clear() oldRoct="+ oldRoct, this);
CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(topLevelFile,
"<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");

CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(topLevelFile,
"<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");
secondDoneLatch.await();
StatusPrinter.print(loggerContext);
statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
secondDoneLatch.await();
StatusPrinter.print(loggerContext);
statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);

} finally {
StatusPrinter.print(loggerContext);
}
}

@Test(timeout = 4000L)
Expand Down Expand Up @@ -233,13 +241,17 @@ public void fallbackToSafeWithIncludedFile_FollowedByRecovery()

loggerContext.getStatusManager().clear();

CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
secondDoneLatch.await();
try {
CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
secondDoneLatch.await();

statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
} finally {
StatusPrinter.print(loggerContext);
}

StatusPrinter.print(loggerContext);
statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
}

private ReconfigureOnChangeTask getRegisteredReconfigureTask() {
Expand Down Expand Up @@ -300,14 +312,21 @@ private ReconfigureOnChangeTask waitForReconfigureOnChangeTaskToRun() throws Int
}

private CountDownLatch waitForReconfigurationToBeDone(ReconfigureOnChangeTask oldTask) throws InterruptedException {

addInfo("waitForReconfigurationToBeDone oldTask=" + oldTask, this);
ReconfigureOnChangeTask roct = oldTask;
while (roct == oldTask) {
roct = getRegisteredReconfigureTask();
Thread.yield();
Thread.sleep(10);
}

CountDownLatch countDownLatch = new CountDownLatch(1);
roct.addListener(new ReconfigurationDoneListener(countDownLatch));
if (roct == null) {
addInfo("roct is null", oldTask);
} else {
roct.addListener(new ReconfigurationDoneListener(countDownLatch));
}
return countDownLatch;
}

Expand Down
3 changes: 2 additions & 1 deletion logback-core/src/main/java/ch/qos/logback/core/ContextBase.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ScheduledFuture;
Expand All @@ -45,7 +46,7 @@ public class ContextBase implements Context, LifeCycle {
// when it changes so that a new instance of propertyMap can be
// serialized. For the time being, we ignore this shortcoming.
Map<String, String> propertyMap = new HashMap<String, String>();
Map<String, Object> objectMap = new HashMap<String, Object>();
Map<String, Object> objectMap = new ConcurrentHashMap<>();

LogbackLock configurationLock = new LogbackLock();

Expand Down
34 changes: 16 additions & 18 deletions logback-core/src/main/java/ch/qos/logback/core/joran/GenericConfigurator.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,7 @@ public abstract class GenericConfigurator extends ContextAwareBase {
protected ModelInterpretationContext modelInterpretationContext;

public ModelInterpretationContext getModelInterpretationContext() {
return modelInterpretationContext;
return this.modelInterpretationContext;
}

public final void doConfigure(URL url) throws JoranException {
Expand Down Expand Up @@ -133,18 +133,22 @@ protected ElementPath initialElementPath() {
return new ElementPath();
}

protected void buildTwoInterpreters() {
protected void buildSaxEventInterpreter() {
RuleStore rs = new SimpleRuleStore(context);
addInstanceRules(rs);
this.saxEventInterpreter = new SaxEventInterpreter(context, rs, initialElementPath());
SaxEventInterpretationContext interpretationContext = saxEventInterpreter.getSaxEventInterpretationContext();
interpretationContext.setContext(context);
modelInterpretationContext = new ModelInterpretationContext(context);
addImplicitRules(saxEventInterpreter);
}


protected void buildModelInterprtationContext() {
this.modelInterpretationContext = new ModelInterpretationContext(context);
addDefaultNestedComponentRegistryRules(modelInterpretationContext.getDefaultNestedComponentRegistry());
}


// this is the most inner form of doConfigure whereto other doConfigure
// methods ultimately delegate
public final void doConfigure(final InputSource inputSource) throws JoranException {
Expand All @@ -159,24 +163,18 @@ public final void doConfigure(final InputSource inputSource) throws JoranExcepti
StatusUtil statusUtil = new StatusUtil(context);
if (statusUtil.noXMLParsingErrorsOccurred(threshold)) {
addInfo("Registering current configuration as safe fallback point");
registerSafeConfiguration(recorder.saxEventList);
registerSafeConfiguration(top);
}
}

public Model buildAndProcessModel(List<SaxEvent> saxEventList) throws JoranException {
Model top = buildModelFromSaxEventList(saxEventList);
processModel(top);
return top;
}

private SaxEventRecorder populateSaxEventRecorder(final InputSource inputSource) throws JoranException {
public SaxEventRecorder populateSaxEventRecorder(final InputSource inputSource) throws JoranException {
SaxEventRecorder recorder = new SaxEventRecorder(context);
recorder.recordEvents(inputSource);
return recorder;
}

public Model buildModelFromSaxEventList(List<SaxEvent> saxEvents) throws JoranException {
buildTwoInterpreters();
buildSaxEventInterpreter();
playSaxEvents(saxEvents);
Model top = saxEventInterpreter.getSaxEventInterpretationContext().peekModel();
return top;
Expand All @@ -187,7 +185,8 @@ private void playSaxEvents(final List<SaxEvent> eventList) throws JoranException
}

public void processModel(Model model) {
DefaultProcessor defaultProcessor = buildDefaultProcessor(context, modelInterpretationContext);
buildModelInterprtationContext();
DefaultProcessor defaultProcessor = buildDefaultProcessor(context, this.modelInterpretationContext);
// disallow simultaneous configurations of the same context
synchronized (context.getConfigurationLock()) {
defaultProcessor.process(model);
Expand All @@ -205,15 +204,14 @@ protected DefaultProcessor buildDefaultProcessor(Context context, ModelInterpret
*
* @since 0.9.30
*/
public void registerSafeConfiguration(List<SaxEvent> eventList) {
context.putObject(SAFE_JORAN_CONFIGURATION, eventList);
public void registerSafeConfiguration(Model top) {
context.putObject(SAFE_JORAN_CONFIGURATION, top);
}

/**
* Recall the event list previously registered as a safe point.
*/
@SuppressWarnings("unchecked")
public List<SaxEvent> recallSafeConfiguration() {
return (List<SaxEvent>) context.getObject(SAFE_JORAN_CONFIGURATION);
public Model recallSafeConfiguration() {
return (Model) context.getObject(SAFE_JORAN_CONFIGURATION);
}
}
7 changes: 2 additions & 5 deletions logback-core/src/main/java/ch/qos/logback/core/joran/JoranConfiguratorBase.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -119,14 +119,11 @@ protected void addImplicitRules(SaxEventInterpreter interpreter) {
interpreter.addImplicitAction(implicitRuleModelAction);
}

@Override
public void buildTwoInterpreters() {
super.buildTwoInterpreters();
public void buildModelInterprtationContext() {
super.buildModelInterprtationContext();
Map<String, Object> omap = modelInterpretationContext.getObjectMap();
omap.put(JoranConstants.APPENDER_BAG, new HashMap<String, Appender<?>>());
omap.put(JoranConstants.APPENDER_REF_BAG, new HashMap<String, AppenderAttachable<?>>());

// omap.put(ActionConst.FILTER_CHAIN_BAG, new HashMap());
}

public SaxEventInterpretationContext getInterpretationContext() {
Expand Down
Loading

0 comments on commit c36af10

Please # to comment.