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