1
2
3
4
5
6
7
8
9
10
11
12
13
14 package ch.qos.logback.classic.sift;
15
16 import ch.qos.logback.classic.ClassicConstants;
17 import ch.qos.logback.classic.ClassicTestConstants;
18 import ch.qos.logback.classic.Level;
19 import ch.qos.logback.classic.Logger;
20 import ch.qos.logback.classic.LoggerContext;
21 import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
22 import ch.qos.logback.classic.joran.JoranConfigurator;
23 import ch.qos.logback.classic.spi.ILoggingEvent;
24 import ch.qos.logback.classic.spi.LoggingEvent;
25 import ch.qos.logback.classic.util.LogbackMDCAdapter;
26 import ch.qos.logback.core.Appender;
27 import ch.qos.logback.core.Context;
28 import ch.qos.logback.core.FileAppender;
29 import ch.qos.logback.core.joran.spi.JoranException;
30 import ch.qos.logback.core.read.ListAppender;
31 import ch.qos.logback.core.rolling.RollingFileAppender;
32 import ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP;
33 import ch.qos.logback.core.rolling.TimeBasedRollingPolicy;
34 import ch.qos.logback.core.sift.AppenderFactory;
35 import ch.qos.logback.core.sift.AppenderTracker;
36 import ch.qos.logback.core.spi.AbstractComponentTracker;
37 import ch.qos.logback.core.spi.ComponentTracker;
38 import ch.qos.logback.core.status.ErrorStatus;
39 import ch.qos.logback.core.status.testUtil.StatusChecker;
40 import ch.qos.logback.core.testUtil.CoreTestConstants;
41 import ch.qos.logback.core.testUtil.RandomUtil;
42
43 import ch.qos.logback.core.testUtil.StringListAppender;
44 import ch.qos.logback.core.util.FileSize;
45 import ch.qos.logback.core.util.StatusPrinter;
46 import org.junit.jupiter.api.AfterEach;
47 import org.junit.jupiter.api.BeforeEach;
48 import org.junit.jupiter.api.Disabled;
49 import org.junit.jupiter.api.Test;
50 import org.slf4j.MDC;
51
52 import java.util.List;
53
54 import static org.junit.jupiter.api.Assertions.assertEquals;
55 import static org.junit.jupiter.api.Assertions.assertFalse;
56 import static org.junit.jupiter.api.Assertions.assertNotNull;
57 import static org.junit.jupiter.api.Assertions.assertNull;
58 import static org.junit.jupiter.api.Assertions.assertTrue;
59
60
61
62 public class SiftingAppenderTest {
63
64 static String SIFT_FOLDER_PREFIX = ClassicTestConstants.JORAN_INPUT_PREFIX + "sift/";
65
66 LoggerContext loggerContext = new LoggerContext();
67 LogbackMDCAdapter logbackMDCAdapter = new LogbackMDCAdapter();
68 Logger logger = loggerContext.getLogger(this.getClass().getName());
69 Logger root = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
70 StatusChecker statusChecker = new StatusChecker(loggerContext);
71 int diff = RandomUtil.getPositiveInt();
72 String randomOutputDir = CoreTestConstants.OUTPUT_DIR_PREFIX + diff + "/";
73 int now = 0;
74
75 protected void configure(String file) throws JoranException {
76 JoranConfigurator jc = new JoranConfigurator();
77 jc.setContext(loggerContext);
78 jc.doConfigure(file);
79 }
80
81 @BeforeEach
82 public void setUp() {
83 loggerContext.setMDCAdapter(logbackMDCAdapter);
84 }
85
86 @AfterEach
87 public void tearDown() {
88
89 }
90
91 @Test
92 public void unsetDefaultValueProperty() throws JoranException {
93 configure(SIFT_FOLDER_PREFIX + "unsetDefaultValueProperty.xml");
94 logger.debug("hello");
95 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
96 assertFalse(sa.isStarted());
97 }
98
99 @Test
100 public void smoke() throws JoranException {
101 configure(SIFT_FOLDER_PREFIX + "smoke.xml");
102 logger.debug("smoke");
103 Appender<ILoggingEvent> appender = getAppenderTracker().find("smokeDefault");
104 assertNotNull(appender);
105 ListAppender<ILoggingEvent> listAppender = (ListAppender<ILoggingEvent>) appender;
106 List<ILoggingEvent> eventList = listAppender.list;
107 assertEquals(1, listAppender.list.size());
108 assertEquals("smoke", eventList.get(0).getMessage());
109 statusChecker.assertIsWarningOrErrorFree();
110 }
111
112 private AppenderTracker<ILoggingEvent> getAppenderTracker() {
113 SiftingAppender ha = (SiftingAppender) root.getAppender("SIFT");
114 return ha.getAppenderTracker();
115 }
116
117 @Test
118 public void zeroNesting() throws JoranException {
119 configure(SIFT_FOLDER_PREFIX + "zeroNesting.xml");
120 logger.debug("hello");
121 logger.debug("hello");
122 logger.debug("hello");
123 logger.debug("hello");
124 logger.debug("hello");
125
126 assertNull(getAppenderTracker());
127
128
129 statusChecker.assertContainsMatch(ErrorStatus.ERROR, "No nested appenders found");
130 }
131
132 @Test
133 public void multipleNesting() throws JoranException {
134 configure(SIFT_FOLDER_PREFIX + "multipleNesting.xml");
135 logger.debug("hello");
136 logger.debug("hello");
137 logger.debug("hello");
138
139 assertNull(getAppenderTracker());
140
141
142 statusChecker.assertContainsMatch(ErrorStatus.ERROR, "Only and only one appender can be nested");
143 }
144
145 @Test
146 public void defaultLayoutRule() throws JoranException {
147 configure(SIFT_FOLDER_PREFIX + "defaultLayoutRule.xml");
148 logger.debug("hello");
149 SiftingAppender ha = (SiftingAppender) root.getAppender("SIFT");
150 StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) ha.getAppenderTracker().find("default");
151
152 assertNotNull(listAppender);
153 List<String> strList = listAppender.strList;
154 assertEquals(1, strList.size());
155 assertEquals("DEBUG hello", strList.get(0));
156 }
157
158 @Test
159 public void fileAppenderCollision() throws JoranException, InterruptedException {
160 loggerContext.putProperty("DIR_PREFIX", randomOutputDir);
161 String key = "collision";
162 configure(SIFT_FOLDER_PREFIX + "fileAppender.xml");
163 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
164
165 long timestamp = System.currentTimeMillis();
166
167 logbackMDCAdapter.put(key, "A-"+diff);
168 logNewEventViaSiftingAppender(sa, timestamp);
169 FileAppender<ILoggingEvent> fileAppenderA = (FileAppender<ILoggingEvent>) sa.getAppenderTracker().find("A-"+diff);
170 assertNotNull(fileAppenderA);
171 assertTrue(fileAppenderA.isStarted());
172 timestamp += ComponentTracker.DEFAULT_TIMEOUT + 1;
173 logbackMDCAdapter.put(key, "B-"+diff);
174 logNewEventViaSiftingAppender(sa, timestamp);
175 assertFalse(fileAppenderA.isStarted());
176
177 logbackMDCAdapter.put(key, "A-"+diff);
178 timestamp += 1;
179 logNewEventViaSiftingAppender(sa, timestamp);
180 FileAppender<ILoggingEvent> fileAppenderA_2 = (FileAppender<ILoggingEvent>) sa.getAppenderTracker().find("A-"+diff);
181 assertTrue(fileAppenderA_2.isStarted());
182
183 }
184
185 private void logNewEventViaSiftingAppender(SiftingAppender sa, long timestamp) {
186 LoggingEvent le = new LoggingEvent("x", logger, Level.INFO, "hello", null, null);
187 le.setTimeStamp(timestamp + ComponentTracker.DEFAULT_TIMEOUT + 1);
188 sa.doAppend(le);
189 }
190
191 @Test
192 public void testWholeCycle() throws JoranException {
193 String mdcKey = "cycle";
194 configure(SIFT_FOLDER_PREFIX + "completeCycle.xml");
195 logbackMDCAdapter.put(mdcKey, "a");
196 logger.debug("smoke");
197 long timestamp = System.currentTimeMillis();
198 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
199 ListAppender<ILoggingEvent> listAppender = (ListAppender<ILoggingEvent>) sa.getAppenderTracker().find("a");
200 assertNotNull(listAppender);
201 List<ILoggingEvent> eventList = listAppender.list;
202 assertEquals(1, listAppender.list.size());
203 assertEquals("smoke", eventList.get(0).getMessage());
204
205 logbackMDCAdapter.remove(mdcKey);
206 logNewEventViaSiftingAppender(sa, timestamp);
207 assertFalse(listAppender.isStarted());
208 assertEquals(1, sa.getAppenderTracker().allKeys().size());
209 assertTrue(sa.getAppenderTracker().allKeys().contains("cycleDefault"));
210 }
211
212 @Test
213 public void sessionFinalizationShouldCauseLingering() throws JoranException {
214 String mdcKey = "linger";
215 String mdcVal = "session" + diff;
216 configure(SIFT_FOLDER_PREFIX + "lingering.xml");
217 logbackMDCAdapter.put(mdcKey, mdcVal);
218 logger.debug("linger 1");
219 logger.debug(ClassicConstants.FINALIZE_SESSION_MARKER, "linger 2");
220 long now = System.currentTimeMillis();
221 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
222 AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
223
224 assertEquals(1, tracker.allKeys().size());
225 Appender<ILoggingEvent> appender = tracker.find(mdcVal);
226 assertTrue(appender.isStarted());
227
228 tracker.removeStaleComponents(now + AppenderTracker.LINGERING_TIMEOUT + 1);
229
230 assertFalse(appender.isStarted());
231
232 assertEquals(0, tracker.allKeys().size());
233 }
234
235 @Test
236 public void localPropertiesShouldBeVisible() throws JoranException {
237 String mdcKey = "localProperty";
238 String mdcVal = "" + diff;
239 String msg = "localPropertiesShouldBeVisible";
240 String prefix = "Y";
241 configure(SIFT_FOLDER_PREFIX + "propertyPropagation.xml");
242
243 logbackMDCAdapter.put(mdcKey, mdcVal);
244 logger.debug(msg);
245 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
246 StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa.getAppenderTracker().find(mdcVal);
247 assertNotNull(listAppender);
248
249 List<String> strList = listAppender.strList;
250 assertEquals(1, listAppender.strList.size());
251 assertEquals(prefix + msg, strList.get(0));
252 }
253
254 @Test
255 public void propertyDefinedWithinSiftElementShouldBeVisible() throws JoranException {
256 String mdcKey = "propertyDefinedWithinSift";
257 String mdcVal = "" + diff;
258 String msg = "propertyDefinedWithinSiftElementShouldBeVisible";
259 String prefix = "Y";
260 configure(SIFT_FOLDER_PREFIX + "propertyDefinedInSiftElement.xml");
261 logbackMDCAdapter.put(mdcKey, mdcVal);
262 logger.debug(msg);
263 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
264 StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa.getAppenderTracker().find(mdcVal);
265 assertNotNull(listAppender);
266 List<String> strList = listAppender.strList;
267 assertEquals(1, listAppender.strList.size());
268 assertEquals(prefix + msg, strList.get(0));
269 }
270
271 @Test
272 public void compositePropertyShouldCombineWithinAndWithoutSiftElement() throws JoranException {
273 String mdcKey = "compositeProperty";
274 String mdcVal = "" + diff;
275 String msg = "compositePropertyShouldCombineWithinAndWithoutSiftElement";
276 String prefix = "composite";
277 configure(SIFT_FOLDER_PREFIX + "compositeProperty.xml");
278 logbackMDCAdapter.put(mdcKey, mdcVal);
279 logger.debug(msg);
280 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
281 StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa.getAppenderTracker().find(mdcVal);
282 assertNotNull(listAppender);
283 List<String> strList = listAppender.strList;
284 assertEquals(1, listAppender.strList.size());
285 assertEquals(prefix + msg, strList.get(0));
286 }
287
288 @Test
289 public void maxAppendersCountPropertyShouldBeHonored() throws JoranException {
290 configure(SIFT_FOLDER_PREFIX + "maxAppenderCount.xml");
291 int max = 5;
292 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
293 String mdcKey = "max";
294 for (int i = 0; i <= max; i++) {
295 logbackMDCAdapter.put(mdcKey, "" + (diff + i));
296 LoggingEvent event = new LoggingEvent("", logger, Level.DEBUG, "max" + i, null, null);
297 event.setTimeStamp(now);
298 sa.doAppend(event);
299 now += AbstractComponentTracker.WAIT_BETWEEN_SUCCESSIVE_REMOVAL_ITERATIONS;
300 }
301 AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
302 assertEquals(max, tracker.allKeys().size());
303 assertNull(tracker.find("" + (diff + 0)));
304 for (int i = 1; i <= max; i++) {
305 assertNotNull(tracker.find("" + (diff + i)));
306 }
307 }
308
309 @Test
310 public void timeoutPropertyShouldBeHonored() throws JoranException, InterruptedException {
311 configure(SIFT_FOLDER_PREFIX + "timeout.xml");
312 long timeout = 30 * 1000;
313 SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
314
315 LoggingEvent event = new LoggingEvent("", logger, Level.DEBUG, "timeout", null, null);
316 event.setTimeStamp(now);
317 sa.doAppend(event);
318
319 AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
320
321 assertEquals(1, tracker.getComponentCount());
322
323 now += timeout + 1;
324 tracker.removeStaleComponents(now);
325 assertEquals(0, tracker.getComponentCount());
326 statusChecker.assertIsErrorFree();
327 }
328
329
330 @Disabled
331 @Test
332 public void programmicSiftingAppender() {
333
334 SiftingAppender connectorAppender = new SiftingAppender();
335 connectorAppender.setContext(loggerContext);
336 connectorAppender.setName("SIFTING_APPENDER");
337
338 MDCBasedDiscriminator discriminator = new MDCBasedDiscriminator();
339 discriminator.setKey("SKEY");
340 discriminator.setDefaultValue("DEF_KEY");
341 discriminator.start();
342 connectorAppender.setDiscriminator(discriminator);
343
344 connectorAppender.setAppenderFactory(new AppenderFactory<ILoggingEvent>() {
345
346 @Override
347 public Appender<ILoggingEvent> buildAppender(Context context, String discriminatingValue) throws JoranException {
348
349 RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<ILoggingEvent>();
350 appender.setName("ROLLING_APPENDER_" + discriminatingValue);
351 appender.setContext(context);
352 appender.setFile("/var/logs/active_" + discriminatingValue + ".log");
353
354 TimeBasedRollingPolicy<ILoggingEvent> policy = new TimeBasedRollingPolicy<ILoggingEvent>();
355 policy.setContext(context);
356 policy.setMaxHistory(365);
357 policy.setFileNamePattern(CoreTestConstants.OUTPUT_DIR_PREFIX + "/logback1127/" + discriminatingValue + "_%d{yyyy_MM_dd}_%i.log");
358 policy.setParent(appender);
359 policy.setCleanHistoryOnStart(true);
360
361 SizeAndTimeBasedFNATP<ILoggingEvent> innerpolicy = new SizeAndTimeBasedFNATP<ILoggingEvent>();
362 innerpolicy.setContext(context);
363 innerpolicy.setMaxFileSize(FileSize.valueOf("5KB"));
364 innerpolicy.setTimeBasedRollingPolicy(policy);
365
366 policy.setTimeBasedFileNamingAndTriggeringPolicy(innerpolicy);
367 policy.start();
368 appender.setRollingPolicy(policy);
369
370 PatternLayoutEncoder pl = new PatternLayoutEncoder();
371 pl.setContext(context);
372 pl.setPattern("%d{yyyy/MM/dd'T'HH:mm:ss} %-5level - %msg\n");
373
374 pl.start();
375 appender.setEncoder(pl);
376
377 appender.start();
378 return appender;
379 }
380 });
381 connectorAppender.start();
382
383 ch.qos.logback.classic.Logger logger = loggerContext.getLogger("org.test");
384 logger.addAppender(connectorAppender);
385 logger.setLevel(Level.DEBUG);
386 logger.setAdditive(false);
387
388 logbackMDCAdapter.put("SKEY", "K1");
389 logger.info("bla1");
390 logbackMDCAdapter.clear();
391
392 logbackMDCAdapter.put("SKEY", "K2");
393 logger.info("bla2");
394 logbackMDCAdapter.clear();
395
396
397
398 }
399 }