001/** 002 * Logback: the reliable, generic, fast and flexible logging framework. 003 * Copyright (C) 1999-2015, QOS.ch. All rights reserved. 004 * 005 * This program and the accompanying materials are dual-licensed under 006 * either the terms of the Eclipse Public License v1.0 as published by 007 * the Eclipse Foundation 008 * 009 * or (per the licensee's choosing) 010 * 011 * under the terms of the GNU Lesser General Public License version 2.1 012 * as published by the Free Software Foundation. 013 */ 014package ch.qos.logback.classic.turbo; 015 016import static ch.qos.logback.core.CoreConstants.MILLIS_IN_ONE_SECOND; 017 018import java.io.File; 019import java.net.URL; 020import java.util.List; 021 022import org.slf4j.Marker; 023 024import ch.qos.logback.classic.Level; 025import ch.qos.logback.classic.Logger; 026import ch.qos.logback.classic.LoggerContext; 027import ch.qos.logback.classic.joran.JoranConfigurator; 028import ch.qos.logback.core.CoreConstants; 029import ch.qos.logback.core.joran.spi.ConfigurationWatchList; 030import ch.qos.logback.core.joran.spi.JoranException; 031import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil; 032import ch.qos.logback.core.model.Model; 033import ch.qos.logback.core.model.ModelUtil; 034import ch.qos.logback.core.spi.FilterReply; 035import ch.qos.logback.core.status.StatusUtil; 036 037/** 038 * Reconfigure a LoggerContext when the configuration file changes. 039 * 040 * @author Ceki Gulcu 041 */ 042public class ReconfigureOnChangeFilter extends TurboFilter { 043 044 /** 045 * Scan for changes in configuration file once every minute. 046 */ 047 // 1 minute - value mentioned in documentation 048 public final static long DEFAULT_REFRESH_PERIOD = 60 * MILLIS_IN_ONE_SECOND; 049 050 long refreshPeriod = DEFAULT_REFRESH_PERIOD; 051 URL mainConfigurationURL; 052 protected volatile long nextCheck; 053 054 ConfigurationWatchList configurationWatchList; 055 056 @Override 057 public void start() { 058 configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(context); 059 if (configurationWatchList != null) { 060 mainConfigurationURL = configurationWatchList.getMainURL(); 061 if (mainConfigurationURL == null) { 062 addWarn("Due to missing top level configuration file, automatic reconfiguration is impossible."); 063 return; 064 } 065 List<File> watchList = configurationWatchList.getCopyOfFileWatchList(); 066 long inSeconds = refreshPeriod / 1000; 067 addInfo("Will scan for changes in [" + watchList + "] every " + inSeconds + " seconds. "); 068 synchronized (configurationWatchList) { 069 updateNextCheck(System.currentTimeMillis()); 070 } 071 super.start(); 072 } else { 073 addWarn("Empty ConfigurationWatchList in context"); 074 } 075 } 076 077 @Override 078 public String toString() { 079 return "ReconfigureOnChangeFilter{" + "invocationCounter=" + invocationCounter + '}'; 080 } 081 082 // The next fields counts the number of time the decide method is called 083 // 084 // IMPORTANT: This field can be updated by multiple threads. It follows that 085 // its values may *not* be incremented sequentially. However, we don't care 086 // about the actual value of the field except that from time to time the 087 // expression (invocationCounter++ & mask) == mask) should be true. 088 private long invocationCounter = 0; 089 090 private volatile long mask = 0xF; 091 private volatile long lastMaskCheck = System.currentTimeMillis(); 092 093 @Override 094 public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) { 095 if (!isStarted()) { 096 return FilterReply.NEUTRAL; 097 } 098 099 // for performance reasons, skip change detection (MASK-1) times out of MASK. 100 // Only once every MASK calls is change detection code executed 101 // Note that MASK is a variable itself. 102 if (((invocationCounter++) & mask) != mask) { 103 return FilterReply.NEUTRAL; 104 } 105 106 long now = System.currentTimeMillis(); 107 108 synchronized (configurationWatchList) { 109 updateMaskIfNecessary(now); 110 if (changeDetected(now)) { 111 // Even though reconfiguration involves resetting the loggerContext, 112 // which clears the list of turbo filters including this instance, it is 113 // still possible for this instance to be subsequently invoked by another 114 // thread if it was already executing when the context was reset. 115 disableSubsequentReconfiguration(); 116 detachReconfigurationToNewThread(); 117 } 118 } 119 120 return FilterReply.NEUTRAL; 121 } 122 123 // experiments indicate that even for CPU intensive applications with 200 or 124 // more threads MASK 125 // values in the order of 0xFFFF is appropriate 126 private static final int MAX_MASK = 0xFFFF; 127 128 // if less than MASK_INCREASE_THRESHOLD milliseconds elapse between invocations 129 // of updateMaskIfNecessary() method, 130 // then the mask should be increased 131 private static final long MASK_INCREASE_THRESHOLD = 100; 132 133 // if more than MASK_DECREASE_THRESHOLD milliseconds elapse between invocations 134 // of updateMaskIfNecessary() method, 135 // then the mask should be decreased 136 private static final long MASK_DECREASE_THRESHOLD = MASK_INCREASE_THRESHOLD * 8; 137 138 // update the mask so as to execute change detection code about once every 100 139 // to 8000 milliseconds. 140 private void updateMaskIfNecessary(long now) { 141 final long timeElapsedSinceLastMaskUpdateCheck = now - lastMaskCheck; 142 lastMaskCheck = now; 143 if (timeElapsedSinceLastMaskUpdateCheck < MASK_INCREASE_THRESHOLD && (mask < MAX_MASK)) { 144 mask = (mask << 1) | 1; 145 } else if (timeElapsedSinceLastMaskUpdateCheck > MASK_DECREASE_THRESHOLD) { 146 mask = mask >>> 2; 147 } 148 } 149 150 // by detaching reconfiguration to a new thread, we release the various 151 // locks held by the current thread, in particular, the AppenderAttachable 152 // reader lock. 153 void detachReconfigurationToNewThread() { 154 addInfo("Detected change in [" + configurationWatchList.getCopyOfFileWatchList() + "]"); 155 context.getScheduledExecutorService().submit(new ReconfiguringThread()); 156 } 157 158 void updateNextCheck(long now) { 159 nextCheck = now + refreshPeriod; 160 } 161 162 protected boolean changeDetected(long now) { 163 if (now >= nextCheck) { 164 updateNextCheck(now); 165 return configurationWatchList.changeDetected(); 166 } 167 return false; 168 } 169 170 void disableSubsequentReconfiguration() { 171 nextCheck = Long.MAX_VALUE; 172 } 173 174 public long getRefreshPeriod() { 175 return refreshPeriod; 176 } 177 178 public void setRefreshPeriod(long refreshPeriod) { 179 this.refreshPeriod = refreshPeriod; 180 } 181 182 class ReconfiguringThread implements Runnable { 183 public void run() { 184 if (mainConfigurationURL == null) { 185 addInfo("Due to missing top level configuration file, skipping reconfiguration"); 186 return; 187 } 188 LoggerContext lc = (LoggerContext) context; 189 addInfo(CoreConstants.RESET_MSG_PREFIX + "named [" + context.getName() + "]"); 190 if (mainConfigurationURL.toString().endsWith("xml")) { 191 performXMLConfiguration(lc); 192 } else if (mainConfigurationURL.toString().endsWith("groovy")) { 193 addError("Groovy configuration disabled due to Java 9 compilation issues."); 194 } 195 } 196 197 private void performXMLConfiguration(LoggerContext lc) { 198 JoranConfigurator jc = new JoranConfigurator(); 199 jc.setContext(context); 200 StatusUtil statusUtil = new StatusUtil(context); 201 Model failSafeTop = jc.recallSafeConfiguration(); 202 URL mainURL = ConfigurationWatchListUtil.getMainWatchURL(context); 203 lc.reset(); 204 long threshold = System.currentTimeMillis(); 205 try { 206 jc.doConfigure(mainConfigurationURL); 207 if (statusUtil.hasXMLParsingErrors(threshold)) { 208 fallbackConfiguration(lc, failSafeTop, mainURL); 209 } 210 } catch (JoranException e) { 211 fallbackConfiguration(lc, failSafeTop, mainURL); 212 } 213 } 214 215 private void fallbackConfiguration(LoggerContext lc, Model failSafeTop, URL mainURL) { 216 JoranConfigurator joranConfigurator = new JoranConfigurator(); 217 joranConfigurator.setContext(context); 218 if (failSafeTop != null) { 219 addWarn("Falling back to previously registered safe configuration."); 220 try { 221 lc.reset(); 222 JoranConfigurator.informContextOfURLUsedForConfiguration(context, mainURL); 223 ModelUtil.resetForReuse(failSafeTop); 224 joranConfigurator.processModel(failSafeTop); 225 addInfo("Re-registering previous fallback configuration once more as a fallback configuration point"); 226 joranConfigurator.registerSafeConfiguration(failSafeTop); 227 } catch (Exception e) { 228 addError("Unexpected exception thrown by a configuration considered safe.", e); 229 } 230 } else { 231 addWarn("No previous configuration to fall back on."); 232 } 233 } 234 } 235}