1
2
3
4
5
6
7
8
9
10
11
12
13
14 package ch.qos.logback.classic.blackbox.joran;
15
16 import ch.qos.logback.classic.Level;
17 import ch.qos.logback.classic.Logger;
18 import ch.qos.logback.classic.LoggerContext;
19 import ch.qos.logback.classic.blackbox.issue.lbclassic135.LoggingRunnable;
20 import ch.qos.logback.classic.joran.*;
21 import ch.qos.logback.classic.model.processor.ConfigurationModelHandlerFull;
22 import ch.qos.logback.core.CoreConstants;
23 import ch.qos.logback.core.testUtil.RunnableWithCounterAndDone;
24 import ch.qos.logback.core.joran.spi.ConfigurationWatchList;
25 import ch.qos.logback.core.joran.spi.JoranException;
26 import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil;
27 import ch.qos.logback.core.spi.ConfigurationEvent;
28 import ch.qos.logback.core.spi.ConfigurationEventListener;
29 import ch.qos.logback.core.status.InfoStatus;
30 import ch.qos.logback.core.status.OnConsoleStatusListener;
31 import ch.qos.logback.core.status.Status;
32 import ch.qos.logback.core.status.WarnStatus;
33 import ch.qos.logback.core.testUtil.CoreTestConstants;
34 import ch.qos.logback.core.testUtil.FileTestUtil;
35 import ch.qos.logback.core.testUtil.RandomUtil;
36 import ch.qos.logback.core.util.StatusPrinter;
37 import ch.qos.logback.core.util.StatusPrinter2;
38 import org.junit.jupiter.api.*;
39
40 import java.io.*;
41 import java.util.List;
42 import java.util.concurrent.CountDownLatch;
43 import java.util.concurrent.ExecutionException;
44 import java.util.concurrent.ScheduledFuture;
45 import java.util.concurrent.TimeUnit;
46
47 import static ch.qos.logback.classic.blackbox.BlackboxClassicTestConstants.JORAN_INPUT_PREFIX;
48 import static ch.qos.logback.classic.joran.ReconfigureOnChangeTask.*;
49 import static org.junit.jupiter.api.Assertions.*;
50
51 public class ReconfigureOnChangeTaskTest extends ReconfigureTaskTestSupport {
52 final static int THREAD_COUNT = 5;
53
54 final static int TIMEOUT = 4;
55 final static int TIMEOUT_LONG = 10;
56
57
58
59 final static String SCAN1_FILE_AS_STR = JORAN_INPUT_PREFIX + "roct/scan 1.xml";
60
61 final static String SCAN_LOGBACK_474_FILE_AS_STR = JORAN_INPUT_PREFIX + "roct/scan_logback_474.xml";
62
63 final static String INCLUSION_SCAN_TOPLEVEL0_AS_STR = JORAN_INPUT_PREFIX + "roct/inclusion/topLevel0.xml";
64
65 final static String INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR = JORAN_INPUT_PREFIX + "roct/inclusion/topByResource.xml";
66
67 final static String INCLUSION_SCAN_INNER0_AS_STR = JORAN_INPUT_PREFIX + "roct/inclusion/inner0.xml";
68
69 final static String INCLUSION_SCAN_INNER1_AS_STR = "target/test-classes/asResource/inner1.xml";
70
71 private static final String SCAN_PERIOD_DEFAULT_FILE_AS_STR = JORAN_INPUT_PREFIX + "roct/scan_period_default.xml";
72
73 Logger logger = loggerContext.getLogger(this.getClass());
74 StatusChecker statusChecker = new StatusChecker(loggerContext);
75 StatusPrinter2 statusPrinter2 = new StatusPrinter2();
76
77
78 @BeforeAll
79 static public void classSetup() {
80 FileTestUtil.makeTestOutputDir();
81 }
82
83 @BeforeEach
84 public void before() {
85 loggerContext.setName("ROCTTest-context" + diff);
86 }
87
88 void configure(File file) throws JoranException {
89 JoranConfigurator jc = new JoranConfigurator();
90 jc.setContext(loggerContext);
91 jc.doConfigure(file);
92 }
93
94 @Test
95 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
96 public void checkBasicLifecyle() throws JoranException, IOException, InterruptedException {
97 File file = new File(SCAN1_FILE_AS_STR);
98 configure(file);
99 List<File> fileList = getConfigurationWatchList(loggerContext);
100 assertThatListContainsFile(fileList, file);
101 statusPrinter2.print(loggerContext);
102 checkThatTaskHasRan();
103 checkThatTaskCanBeStopped();
104 }
105
106 private void checkThatTaskCanBeStopped() {
107 ScheduledFuture<?> future = loggerContext.getCopyOfScheduledFutures().get(0);
108 loggerContext.stop();
109 assertTrue(future.isCancelled());
110 }
111
112 private void checkThatTaskHasRan() throws InterruptedException {
113 waitForReconfigureOnChangeTaskToRun();
114 }
115
116 List<File> getConfigurationWatchList(LoggerContext lc) {
117 ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(lc);
118 return configurationWatchList.getCopyOfFileWatchList();
119 }
120
121 @Test
122 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
123 public void scanWithFileInclusion() throws JoranException, IOException, InterruptedException {
124 File topLevelFile = new File(INCLUSION_SCAN_TOPLEVEL0_AS_STR);
125 File innerFile = new File(INCLUSION_SCAN_INNER0_AS_STR);
126 configure(topLevelFile);
127 List<File> fileList = getConfigurationWatchList(loggerContext);
128 assertThatListContainsFile(fileList, topLevelFile);
129 assertThatListContainsFile(fileList, innerFile);
130 checkThatTaskHasRan();
131 checkThatTaskCanBeStopped();
132 }
133
134 @Test
135 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
136 public void scanWithResourceInclusion() throws JoranException, IOException, InterruptedException {
137 File topLevelFile = new File(INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR);
138 File innerFile = new File(INCLUSION_SCAN_INNER1_AS_STR);
139 configure(topLevelFile);
140 List<File> fileList = getConfigurationWatchList(loggerContext);
141 assertThatListContainsFile(fileList, topLevelFile);
142 assertThatListContainsFile(fileList, innerFile);
143 }
144
145 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
146 @Test
147 public void propertiesConfigurationTest() throws IOException, JoranException, InterruptedException {
148 String loggerName = "abc";
149 String propertiesFileStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "roct-" + diff + ".properties";
150 File propertiesFile = new File(propertiesFileStr);
151 String configurationStr = "<configuration debug=\"true\" scan=\"true\" scanPeriod=\"10 millisecond\"><propertiesConfigurator file=\"" + propertiesFileStr + "\"/></configuration>";
152 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=INFO");
153 configure(asBAIS(configurationStr));
154 Logger abcLogger = loggerContext.getLogger(loggerName);
155 assertEquals(Level.INFO, abcLogger.getLevel());
156
157 CountDownLatch changeDetectedLatch0 = registerChangeDetectedListener();
158 CountDownLatch configurationDoneLatch0 = registerPartialConfigurationEndedSuccessfullyEventListener();
159
160 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=WARN");
161 changeDetectedLatch0.await();
162 configurationDoneLatch0.await();
163 assertEquals(Level.WARN, abcLogger.getLevel());
164
165 CountDownLatch changeDetectedLatch1 = registerChangeDetectedListener();
166 CountDownLatch configurationDoneLatch1 = registerPartialConfigurationEndedSuccessfullyEventListener();
167 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=ERROR");
168 changeDetectedLatch1.await();
169 configurationDoneLatch1.await();
170
171 assertEquals(Level.ERROR, abcLogger.getLevel());
172
173 }
174
175 @Disabled
176 @Test
177 void propertiesFromHTTPS() throws InterruptedException, UnsupportedEncodingException, JoranException {
178 String loggerName = "com.bazinga";
179 String propertiesURLStr = "https://www.qos.ch/foo.properties";
180 Logger aLogger = loggerContext.getLogger(loggerName);
181 String configurationStr = "<configuration debug=\"true\" scan=\"true\" scanPeriod=\"10 millisecond\"><propertiesConfigurator url=\"" + propertiesURLStr + "\"/></configuration>";
182
183 configure(asBAIS(configurationStr));
184 assertEquals(Level.WARN, aLogger.getLevel());
185 System.out.println("first phase OK");
186 CountDownLatch changeDetectedLatch0 = registerChangeDetectedListener();
187 CountDownLatch configurationDoneLatch0 = registerPartialConfigurationEndedSuccessfullyEventListener();
188
189 changeDetectedLatch0.await();
190 System.out.println("after changeDetectedLatch0.await();");
191 configurationDoneLatch0.await();
192 assertEquals(Level.ERROR, aLogger.getLevel());
193 }
194
195
196 @Test
197 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
198 public void reconfigurationIsNotPossibleInTheAbsenceOfATopFile() throws IOException, JoranException, InterruptedException {
199
200 ReconfigurationTaskRegisteredConfigEventListener listener = new ReconfigurationTaskRegisteredConfigEventListener();
201 loggerContext.addConfigurationEventListener(listener);
202 String configurationStr = "<configuration scan=\"true\" scanPeriod=\"50 millisecond\"><include resource=\"asResource/inner1.xml\"/></configuration>";
203 configure(asBAIS(configurationStr));
204
205 ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(loggerContext);
206 assertNull(configurationWatchList);
207 assertFalse(ConfigurationWatchListUtil.watchPredicateFulfilled(loggerContext));
208 statusChecker.containsMatch(Status.WARN, ConfigurationModelHandlerFull.FAILED_WATCH_PREDICATE_MESSAGE_1);
209 StatusPrinter.print(loggerContext);
210
211 assertFalse(listener.changeDetectorRegisteredEventOccurred);
212 assertEquals(0, loggerContext.getCopyOfScheduledFutures().size());
213 }
214
215 @Test
216 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
217 public void fallbackToSafe_FollowedByRecovery() throws IOException, JoranException, InterruptedException {
218 addInfo("Start fallbackToSafe_FollowedByRecovery", this);
219 String path = CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_fallbackToSafe-" + diff + ".xml";
220 File topLevelFile = new File(path);
221 writeToFile(topLevelFile, "<configuration scan=\"true\" scanPeriod=\"25 millisecond\"><root level=\"ERROR\"/></configuration> ");
222
223 addResetResistantOnConsoleStatusListener();
224 configure(topLevelFile);
225
226 CountDownLatch changeDetectedLatch = registerChangeDetectedListener();
227 CountDownLatch configurationDoneLatch = registerNewReconfigurationDoneSuccessfullyListener();
228
229 String badXML = "<configuration scan=\"true\" scanPeriod=\"5 millisecond\">\n" + " <root></configuration>";
230 writeToFile(topLevelFile, badXML);
231 changeDetectedLatch.await();
232 configurationDoneLatch.await();
233
234 statusChecker.assertContainsMatch(Status.ERROR, CoreConstants.XML_PARSING);
235 statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
236 statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
237
238
239 loggerContext.getStatusManager().clear();
240
241 addInfo("RECOVERY - Writing error-free config file ", this);
242 CountDownLatch secondConfigEndedLatch = registerNewReconfigurationDoneSuccessfullyListener();
243
244
245 writeToFile(topLevelFile, "<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");
246
247 try {
248 addInfo("Awaiting secondConfigEndedLatch ", this);
249 secondConfigEndedLatch.await(5, TimeUnit.SECONDS);
250 addInfo("after secondConfigEndedLatch.await ", this);
251 statusChecker.assertIsErrorFree();
252 statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
253 } finally {
254 StatusPrinter.print(loggerContext);
255 }
256 }
257
258 private void addResetResistantOnConsoleStatusListener() {
259 if (1 == 1)
260 return;
261 OnConsoleStatusListener ocs = new OnConsoleStatusListener();
262 ocs.setContext(loggerContext);
263 ocs.setResetResistant(true);
264 ocs.start();
265 loggerContext.getStatusManager().add(ocs);
266 }
267
268 @Test
269 @Timeout(value = TIMEOUT_LONG, unit = TimeUnit.SECONDS)
270 public void fallbackToSafeWithIncludedFile_FollowedByRecovery() throws IOException, JoranException, InterruptedException, ExecutionException {
271 String topLevelFileAsStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_top-" + diff + ".xml";
272 String innerFileAsStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_inner-" + diff + ".xml";
273 File topLevelFile = new File(topLevelFileAsStr);
274 writeToFile(topLevelFile,
275 "<configuration xdebug=\"true\" scan=\"true\" scanPeriod=\"5 millisecond\"><include file=\"" + innerFileAsStr + "\"/></configuration> ");
276
277 File innerFile = new File(innerFileAsStr);
278 writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
279 addResetResistantOnConsoleStatusListener();
280
281 ReconfigurationTaskRegisteredConfigEventListener roctRegisteredListener = new ReconfigurationTaskRegisteredConfigEventListener();
282 loggerContext.addConfigurationEventListener(roctRegisteredListener);
283
284 configure(topLevelFile);
285
286 ReconfigureOnChangeTask roct = roctRegisteredListener.reconfigureOnChangeTask;
287
288 System.out.println("===================================================");
289
290 CountDownLatch changeDetectedLatch = registerChangeDetectedListener();
291 CountDownLatch configurationDoneLatch = registerNewReconfigurationDoneSuccessfullyListener(roct);
292
293 writeToFile(innerFile, "<included>\n<root>\n</included>");
294 changeDetectedLatch.await();
295 configurationDoneLatch.await();
296 addInfo("Woke from configurationDoneLatch.await()", this);
297
298 statusChecker.assertContainsMatch(Status.ERROR, CoreConstants.XML_PARSING);
299 statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
300 statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
301
302 loggerContext.getStatusManager().clear();
303
304 CountDownLatch secondDoneLatch = registerNewReconfigurationDoneSuccessfullyListener();
305 writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
306 secondDoneLatch.await();
307
308 statusChecker.assertIsErrorFree();
309 statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
310
311 }
312
313 CountDownLatch registerNewReconfigurationDoneSuccessfullyListener() {
314 return registerNewReconfigurationDoneSuccessfullyListener(null);
315 }
316
317 CountDownLatch registerNewReconfigurationDoneSuccessfullyListener(ReconfigureOnChangeTask roct) {
318 CountDownLatch latch = new CountDownLatch(1);
319 ReconfigurationDoneListener reconfigurationDoneListener = new ReconfigurationDoneListener(latch, roct);
320 loggerContext.addConfigurationEventListener(reconfigurationDoneListener);
321 return latch;
322 }
323
324 class RunMethodInvokedListener implements ConfigurationEventListener {
325 CountDownLatch countDownLatch;
326 ReconfigureOnChangeTask reconfigureOnChangeTask;
327
328 RunMethodInvokedListener(CountDownLatch countDownLatch) {
329 this.countDownLatch = countDownLatch;
330 }
331
332 @Override
333 public void listen(ConfigurationEvent configurationEvent) {
334 switch (configurationEvent.getEventType()) {
335 case CHANGE_DETECTOR_RUNNING:
336 countDownLatch.countDown();
337 Object data = configurationEvent.getData();
338 if (data instanceof ReconfigureOnChangeTask) {
339 reconfigureOnChangeTask = (ReconfigureOnChangeTask) data;
340 }
341 break;
342 default:
343 }
344 }
345 }
346
347 private ReconfigureOnChangeTask waitForReconfigureOnChangeTaskToRun() throws InterruptedException {
348 addInfo("entering waitForReconfigureOnChangeTaskToRun", this);
349
350 CountDownLatch countDownLatch = new CountDownLatch(1);
351 RunMethodInvokedListener runMethodInvokedListener = new RunMethodInvokedListener(countDownLatch);
352
353 loggerContext.addConfigurationEventListener(runMethodInvokedListener);
354 countDownLatch.await();
355 return runMethodInvokedListener.reconfigureOnChangeTask;
356 }
357
358 private RunnableWithCounterAndDone[] buildRunnableArray(File configFile, UpdateType updateType) {
359 RunnableWithCounterAndDone[] rArray = new RunnableWithCounterAndDone[THREAD_COUNT];
360 rArray[0] = new UpdaterRunnable(this, configFile, updateType);
361 for (int i = 1; i < THREAD_COUNT; i++) {
362 rArray[i] = new LoggingRunnable(logger);
363 }
364 return rArray;
365 }
366
367 @Test
368 public void checkReconfigureTaskScheduledWhenDefaultScanPeriodUsed() throws JoranException {
369 File file = new File(SCAN_PERIOD_DEFAULT_FILE_AS_STR);
370 configure(file);
371
372 final List<ScheduledFuture<?>> scheduledFutures = loggerContext.getCopyOfScheduledFutures();
373
374 assertFalse(scheduledFutures.isEmpty());
375 statusChecker.containsMatch("No 'scanPeriod' specified. Defaulting to");
376
377 }
378
379
380 @Test
381 @Timeout(value = 4, unit = TimeUnit.SECONDS)
382 public void scan_LOGBACK_474() throws JoranException, IOException, InterruptedException {
383 File file = new File(SCAN_LOGBACK_474_FILE_AS_STR);
384 addResetResistantOnConsoleStatusListener();
385 configure(file);
386
387 int expectedResets = 2;
388 ReconfigureOnChangeTaskHarness harness = new ReconfigureOnChangeTaskHarness(loggerContext, expectedResets);
389
390 RunnableWithCounterAndDone[] runnableArray = buildRunnableArray(file, UpdateType.TOUCH);
391 harness.execute(runnableArray);
392
393 addInfo("scan_LOGBACK_474 end of execution ", this);
394 checkResetCount(expectedResets);
395 }
396
397 private void assertThatListContainsFile(List<File> fileList, File file) {
398
399 assertTrue(fileList.contains(file.getAbsoluteFile()));
400 }
401
402 private void checkResetCount(int expected) {
403 StatusChecker checker = new StatusChecker(loggerContext);
404 checker.assertIsErrorFree();
405
406 int effectiveResets = checker.matchCount(CoreConstants.RESET_MSG_PREFIX);
407 assertEquals(expected, effectiveResets);
408
409
410
411
412
413
414
415
416 }
417
418 void addInfo(String msg, Object o) {
419 loggerContext.getStatusManager().add(new InfoStatus(msg, o));
420 }
421
422 void addWarn(String msg, Object o) {
423 loggerContext.getStatusManager().add(new WarnStatus(msg, o));
424 }
425
426 enum UpdateType {
427 TOUCH, MALFORMED, MALFORMED_INNER
428 }
429
430 void writeToFile(File file, String contents) throws IOException {
431 FileWriter fw = new FileWriter(file);
432 fw.write(contents);
433 fw.close();
434
435
436 boolean success = file.setLastModified(System.currentTimeMillis() + RandomUtil.getPositiveInt());
437 if (!success) {
438 addWarn("failed to setLastModified on file " + file, this);
439 }
440 }
441
442 }