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 checkThatTaskHasRan();
102 checkThatTaskCanBeStopped();
103 }
104
105 private void checkThatTaskCanBeStopped() {
106 ScheduledFuture<?> future = loggerContext.getCopyOfScheduledFutures().get(0);
107 loggerContext.stop();
108 assertTrue(future.isCancelled());
109 }
110
111 private void checkThatTaskHasRan() throws InterruptedException {
112 waitForReconfigureOnChangeTaskToRun();
113 }
114
115 List<File> getConfigurationWatchList(LoggerContext lc) {
116 ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(lc);
117 return configurationWatchList.getCopyOfFileWatchList();
118 }
119
120 @Test
121 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
122 public void scanWithFileInclusion() throws JoranException, IOException, InterruptedException {
123 File topLevelFile = new File(INCLUSION_SCAN_TOPLEVEL0_AS_STR);
124 File innerFile = new File(INCLUSION_SCAN_INNER0_AS_STR);
125 configure(topLevelFile);
126 List<File> fileList = getConfigurationWatchList(loggerContext);
127 assertThatListContainsFile(fileList, topLevelFile);
128 assertThatListContainsFile(fileList, innerFile);
129 checkThatTaskHasRan();
130 checkThatTaskCanBeStopped();
131 }
132
133 @Test
134 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
135 public void scanWithResourceInclusion() throws JoranException, IOException, InterruptedException {
136 File topLevelFile = new File(INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR);
137 File innerFile = new File(INCLUSION_SCAN_INNER1_AS_STR);
138 configure(topLevelFile);
139 List<File> fileList = getConfigurationWatchList(loggerContext);
140 assertThatListContainsFile(fileList, topLevelFile);
141 assertThatListContainsFile(fileList, innerFile);
142 }
143
144 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
145 @Test
146 public void propertiesConfigurationTest() throws IOException, JoranException, InterruptedException {
147 String loggerName = "abc";
148 String propertiesFileStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "roct-" + diff + ".properties";
149 File propertiesFile = new File(propertiesFileStr);
150 String configurationStr = "<configuration debug=\"true\" scan=\"true\" scanPeriod=\"10 millisecond\"><propertiesConfigurator file=\"" + propertiesFileStr + "\"/></configuration>";
151 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=INFO");
152 configure(asBAIS(configurationStr));
153 Logger abcLogger = loggerContext.getLogger(loggerName);
154 assertEquals(Level.INFO, abcLogger.getLevel());
155
156 CountDownLatch changeDetectedLatch0 = registerChangeDetectedListener();
157 CountDownLatch configurationDoneLatch0 = registerPartialConfigurationEndedSuccessfullyEventListener();
158
159 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=WARN");
160 changeDetectedLatch0.await();
161 configurationDoneLatch0.await();
162 assertEquals(Level.WARN, abcLogger.getLevel());
163
164 CountDownLatch changeDetectedLatch1 = registerChangeDetectedListener();
165 CountDownLatch configurationDoneLatch1 = registerPartialConfigurationEndedSuccessfullyEventListener();
166 writeToFile(propertiesFile, PropertiesConfigurator.LOGBACK_LOGGER_PREFIX + loggerName+"=ERROR");
167 changeDetectedLatch1.await();
168 configurationDoneLatch1.await();
169
170 assertEquals(Level.ERROR, abcLogger.getLevel());
171
172 }
173
174 @Disabled
175 @Test
176 void propertiesFromHTTPS() throws InterruptedException, UnsupportedEncodingException, JoranException {
177 String loggerName = "com.bazinga";
178 String propertiesURLStr = "https://www.qos.ch/foo.properties";
179 Logger aLogger = loggerContext.getLogger(loggerName);
180 String configurationStr = "<configuration debug=\"true\" scan=\"true\" scanPeriod=\"10 millisecond\"><propertiesConfigurator url=\"" + propertiesURLStr + "\"/></configuration>";
181
182 configure(asBAIS(configurationStr));
183 assertEquals(Level.WARN, aLogger.getLevel());
184 System.out.println("first phase OK");
185 CountDownLatch changeDetectedLatch0 = registerChangeDetectedListener();
186 CountDownLatch configurationDoneLatch0 = registerPartialConfigurationEndedSuccessfullyEventListener();
187
188 changeDetectedLatch0.await();
189 System.out.println("after changeDetectedLatch0.await();");
190 configurationDoneLatch0.await();
191 assertEquals(Level.ERROR, aLogger.getLevel());
192 }
193
194
195 @Test
196 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
197 public void reconfigurationIsNotPossibleInTheAbsenceOfATopFile() throws IOException, JoranException, InterruptedException {
198
199 ReconfigurationTaskRegisteredConfigEventListener listener = new ReconfigurationTaskRegisteredConfigEventListener();
200 loggerContext.addConfigurationEventListener(listener);
201 String configurationStr = "<configuration scan=\"true\" scanPeriod=\"50 millisecond\"><include resource=\"asResource/inner1.xml\"/></configuration>";
202 configure(asBAIS(configurationStr));
203
204 ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(loggerContext);
205
206 assertNotNull(configurationWatchList);
207 assertFalse(ConfigurationWatchListUtil.watchPredicateFulfilled(loggerContext));
208 statusChecker.containsMatch(Status.WARN, ConfigurationModelHandlerFull.FAILED_WATCH_PREDICATE_MESSAGE_1);
209
210 assertFalse(listener.changeDetectorRegisteredEventOccurred);
211 assertEquals(0, loggerContext.getCopyOfScheduledFutures().size());
212 }
213
214 @Test
215 @Timeout(value = TIMEOUT, unit = TimeUnit.SECONDS)
216 public void fallbackToSafe_FollowedByRecovery() throws IOException, JoranException, InterruptedException {
217 addInfo("Start fallbackToSafe_FollowedByRecovery", this);
218 String path = CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_fallbackToSafe-" + diff + ".xml";
219 File topLevelFile = new File(path);
220 writeToFile(topLevelFile, "<configuration scan=\"true\" scanPeriod=\"25 millisecond\"><root level=\"ERROR\"/></configuration> ");
221
222 addResetResistantOnConsoleStatusListener();
223 configure(topLevelFile);
224
225 CountDownLatch changeDetectedLatch = registerChangeDetectedListener();
226 CountDownLatch configurationDoneLatch = registerNewReconfigurationDoneSuccessfullyListener();
227
228 String badXML = "<configuration scan=\"true\" scanPeriod=\"5 millisecond\">\n" + " <root></configuration>";
229 writeToFile(topLevelFile, badXML);
230 changeDetectedLatch.await();
231 configurationDoneLatch.await();
232
233 statusChecker.assertContainsMatch(Status.ERROR, CoreConstants.XML_PARSING);
234 statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
235 statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
236
237
238 loggerContext.getStatusManager().clear();
239
240 addInfo("RECOVERY - Writing error-free config file ", this);
241 CountDownLatch secondConfigEndedLatch = registerNewReconfigurationDoneSuccessfullyListener();
242
243
244 writeToFile(topLevelFile, "<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");
245
246 try {
247 addInfo("Awaiting secondConfigEndedLatch ", this);
248 secondConfigEndedLatch.await(5, TimeUnit.SECONDS);
249 addInfo("after secondConfigEndedLatch.await ", this);
250 statusChecker.assertIsErrorFree();
251 statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
252 } finally {
253
254 }
255 }
256
257 private void addResetResistantOnConsoleStatusListener() {
258
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
289 CountDownLatch changeDetectedLatch = registerChangeDetectedListener();
290 CountDownLatch configurationDoneLatch = registerNewReconfigurationDoneSuccessfullyListener(roct);
291
292 writeToFile(innerFile, "<included>\n<root>\n</included>");
293 changeDetectedLatch.await();
294 configurationDoneLatch.await();
295 addInfo("Woke from configurationDoneLatch.await()", this);
296
297 statusChecker.assertContainsMatch(Status.ERROR, CoreConstants.XML_PARSING);
298 statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
299 statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
300
301
302
303 loggerContext.getStatusManager().clear();
304
305 CountDownLatch secondDoneLatch = registerNewReconfigurationDoneSuccessfullyListener();
306 writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
307 secondDoneLatch.await();
308
309 statusChecker.assertIsErrorFree();
310 statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
311
312 }
313
314 CountDownLatch registerNewReconfigurationDoneSuccessfullyListener() {
315 return registerNewReconfigurationDoneSuccessfullyListener(null);
316 }
317
318 CountDownLatch registerNewReconfigurationDoneSuccessfullyListener(ReconfigureOnChangeTask roct) {
319 CountDownLatch latch = new CountDownLatch(1);
320 ReconfigurationDoneListener reconfigurationDoneListener = new ReconfigurationDoneListener(latch, roct);
321 loggerContext.addConfigurationEventListener(reconfigurationDoneListener);
322 return latch;
323 }
324
325 class RunMethodInvokedListener implements ConfigurationEventListener {
326 CountDownLatch countDownLatch;
327 ReconfigureOnChangeTask reconfigureOnChangeTask;
328
329 RunMethodInvokedListener(CountDownLatch countDownLatch) {
330 this.countDownLatch = countDownLatch;
331 }
332
333 @Override
334 public void listen(ConfigurationEvent configurationEvent) {
335 switch (configurationEvent.getEventType()) {
336 case CHANGE_DETECTOR_RUNNING:
337 countDownLatch.countDown();
338 Object data = configurationEvent.getData();
339 if (data instanceof ReconfigureOnChangeTask) {
340 reconfigureOnChangeTask = (ReconfigureOnChangeTask) data;
341 }
342 break;
343 default:
344 }
345 }
346 }
347
348 private ReconfigureOnChangeTask waitForReconfigureOnChangeTaskToRun() throws InterruptedException {
349 addInfo("entering waitForReconfigureOnChangeTaskToRun", this);
350
351 CountDownLatch countDownLatch = new CountDownLatch(1);
352 RunMethodInvokedListener runMethodInvokedListener = new RunMethodInvokedListener(countDownLatch);
353
354 loggerContext.addConfigurationEventListener(runMethodInvokedListener);
355 countDownLatch.await();
356 return runMethodInvokedListener.reconfigureOnChangeTask;
357 }
358
359 private RunnableWithCounterAndDone[] buildRunnableArray(File configFile, UpdateType updateType) {
360 RunnableWithCounterAndDone[] rArray = new RunnableWithCounterAndDone[THREAD_COUNT];
361 rArray[0] = new UpdaterRunnable(this, configFile, updateType);
362 for (int i = 1; i < THREAD_COUNT; i++) {
363 rArray[i] = new LoggingRunnable(logger);
364 }
365 return rArray;
366 }
367
368 @Test
369 public void checkReconfigureTaskScheduledWhenDefaultScanPeriodUsed() throws JoranException {
370 File file = new File(SCAN_PERIOD_DEFAULT_FILE_AS_STR);
371 configure(file);
372
373 final List<ScheduledFuture<?>> scheduledFutures = loggerContext.getCopyOfScheduledFutures();
374
375 assertFalse(scheduledFutures.isEmpty());
376 statusChecker.containsMatch("No 'scanPeriod' specified. Defaulting to");
377
378 }
379
380
381 @Test
382 @Timeout(value = 4, unit = TimeUnit.SECONDS)
383 public void scan_LOGBACK_474() throws JoranException, IOException, InterruptedException {
384 File file = new File(SCAN_LOGBACK_474_FILE_AS_STR);
385 addResetResistantOnConsoleStatusListener();
386 configure(file);
387
388 int expectedResets = 2;
389 ReconfigureOnChangeTaskHarness harness = new ReconfigureOnChangeTaskHarness(loggerContext, expectedResets);
390
391 RunnableWithCounterAndDone[] runnableArray = buildRunnableArray(file, UpdateType.TOUCH);
392 harness.execute(runnableArray);
393
394 addInfo("scan_LOGBACK_474 end of execution ", this);
395 checkResetCount(expectedResets);
396 }
397
398 private void assertThatListContainsFile(List<File> fileList, File file) {
399
400 assertTrue(fileList.contains(file.getAbsoluteFile()));
401 }
402
403 private void checkResetCount(int expected) {
404 StatusChecker checker = new StatusChecker(loggerContext);
405 checker.assertIsErrorFree();
406
407 int effectiveResets = checker.matchCount(CoreConstants.RESET_MSG_PREFIX);
408 assertEquals(expected, effectiveResets);
409
410
411
412
413
414
415
416
417 }
418
419 void addInfo(String msg, Object o) {
420 loggerContext.getStatusManager().add(new InfoStatus(msg, o));
421 }
422
423 void addWarn(String msg, Object o) {
424 loggerContext.getStatusManager().add(new WarnStatus(msg, o));
425 }
426
427 enum UpdateType {
428 TOUCH, MALFORMED, MALFORMED_INNER
429 }
430
431 void writeToFile(File file, String contents) throws IOException {
432 FileWriter fw = new FileWriter(file);
433 fw.write(contents);
434 fw.close();
435
436
437 boolean success = file.setLastModified(System.currentTimeMillis() + RandomUtil.getPositiveInt());
438 if (!success) {
439 addWarn("failed to setLastModified on file " + file, this);
440 }
441 }
442
443 }