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