1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16 package org.spf4j.test.log;
17
18 import org.spf4j.test.matchers.LogMatchers;
19 import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
20 import java.util.ArrayDeque;
21 import java.util.HashSet;
22 import java.util.Set;
23 import java.util.concurrent.TimeUnit;
24 import java.util.stream.Collectors;
25 import org.hamcrest.Matcher;
26 import org.junit.Assert;
27 import org.hamcrest.Matchers;
28 import org.junit.Ignore;
29 import org.junit.Test;
30 import org.slf4j.Logger;
31 import org.slf4j.LoggerFactory;
32 import org.slf4j.Marker;
33 import org.slf4j.MarkerFactory;
34 import org.spf4j.base.CoreTextMediaType;
35 import org.spf4j.base.ExecutionContexts;
36 import org.spf4j.base.avro.Method;
37 import org.spf4j.log.Level;
38 import org.spf4j.test.log.annotations.CollectLogs;
39 import org.spf4j.test.log.annotations.ExpectLog;
40 import org.spf4j.test.log.annotations.PrintLogs;
41 import org.spf4j.test.log.annotations.PrintLogsConfigs;
42
43
44
45
46 @SuppressFBWarnings({ "LO_INCORRECT_NUMBER_OF_ANCHOR_PARAMETERS", "FCCD_FIND_CLASS_CIRCULAR_DEPENDENCY" })
47 public class TestLoggerFactoryTest {
48
49 private static final Logger LOG = LoggerFactory.getLogger(TestLoggerFactoryTest.class);
50
51 @Test(timeout = 1000)
52 public void testSomeHandler() {
53 TestLoggers sys = TestLoggers.sys();
54 LogAssert expect = sys.expect("", Level.TRACE, LogMatchers.hasAttachment(Attachments.PRINTED));
55 sys.print("org.spf4j.test", Level.TRACE);
56 LOG.trace("test");
57 expect.assertObservation();
58 }
59
60 @Test
61 @PrintLogs(category = "org.spf4", ideMinLevel = Level.TRACE, minLevel = Level.TRACE)
62 public void testSomeHandler2() {
63 LogAssert expect = TestLoggers.sys().expect("", Level.TRACE, LogMatchers.hasAttachment(Attachments.PRINTED));
64 LOG.trace("test");
65 expect.assertObservation();
66 }
67
68
69 @Test
70 @PrintLogsConfigs(
71 {
72 @PrintLogs(ideMinLevel = Level.TRACE),
73 @PrintLogs(category = "com.sun", ideMinLevel = Level.WARN)
74 }
75 )
76 @CollectLogs(minLevel = Level.TRACE)
77 public void testLogging() {
78 TestLoggers tLog = TestLoggers.sys();
79 logTests();
80 logMarkerTests();
81 LogAssert expect = tLog.expect("org.spf4j.test", Level.ERROR,
82 LogMatchers.hasMatchingFormat(Matchers.equalTo("Booo")));
83 LOG.error("Booo", new RuntimeException());
84 expect.assertObservation();
85 }
86
87 public static void logTests() {
88 LOG.trace("Hello logger", new RuntimeException());
89 LOG.trace("Hello logger");
90 LOG.trace("Hello logger {}", 1);
91 LOG.trace("Hello logger {} {} {}", 1, 2, 3);
92 LOG.trace("Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
93 LOG.debug("Hello logger", new RuntimeException());
94 LOG.debug("Hello logger");
95 LOG.debug("Hello logger {}", 1);
96 LOG.debug("Hello logger {} {} {}", 1, 2, 3);
97 LOG.debug("Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
98 LOG.info("Hello logger", new RuntimeException());
99 LOG.info("Hello logger");
100 LOG.info("Hello logger {}", 1);
101 LOG.info("Hello logger {} {} {}", 1, 2, 3);
102 LOG.info("Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
103 LOG.warn("Hello logger", new RuntimeException());
104 LOG.warn("Hello logger");
105 LOG.warn("Hello logger {}", 1);
106 LOG.warn("Hello logger {} {} {}", 1, 2, 3);
107 LOG.warn("Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
108 LOG.debug("Some message with {}", new Object() {
109 @Override
110 public String toString() {
111 throw new IllegalStateException();
112 }
113 });
114 LogAssert expect = TestLoggers.sys().expect("org.spf4j.test", Level.ERROR, 5,
115 LogMatchers.hasMatchingFormat(Matchers.containsString("Hello logger")));
116 LOG.error("Hello logger", new RuntimeException());
117 LOG.error("Hello logger");
118 LOG.error("Hello logger {}", 1);
119 LOG.error("Hello logger {} {} {}", 1, 2, 3);
120 LOG.error("Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
121 expect.assertObservation();
122 }
123
124 public static void logMarkerTests() {
125 Marker marker = MarkerFactory.getMarker("TEST");
126 Marker marker2 = MarkerFactory.getMarker("TEST2");
127 marker2.add(marker);
128 marker2.add(MarkerFactory.getMarker("TEST3"));
129
130 LOG.trace(marker, "Hello logger", new RuntimeException());
131 LOG.trace(marker, "Hello logger");
132 LOG.trace(marker, "Hello logger {}", 1);
133 LOG.trace(marker, "Hello logger {} {} {}", 1, 2, 3);
134 LOG.trace(marker, "Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
135 LOG.debug(marker, "Hello logger", new RuntimeException());
136 LOG.debug(marker, "Hello logger");
137 LOG.debug(marker, "Hello logger {}", 1);
138 LOG.debug(marker, "Hello logger {} {} {}", 1, 2, 3);
139 LOG.debug(marker, "Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
140 LOG.info(marker, "Hello logger", new RuntimeException());
141 LOG.info(marker2, "Hello logger");
142 LOG.info(marker2, "Hello logger {}", 1);
143 LOG.info(marker2, "Hello logger {} {} {}", 1, 2, 3);
144 LOG.info(marker2, "Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
145 LOG.warn(marker, "Hello logger", new RuntimeException());
146 LOG.warn(marker, "Hello logger");
147 LOG.warn(marker, "Hello logger {}", 1);
148 LOG.warn(marker, "Hello logger {} {} {}", 1, 2, 3);
149 LOG.warn(marker, "Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
150 LogAssert expect = TestLoggers.sys().expect("org.spf4j.test", Level.ERROR, 5,
151 Matchers.allOf(
152 LogMatchers.hasMatchingFormat(Matchers.containsString("Hello logger")),
153 LogMatchers.hasMarker(marker)));
154 LOG.error(marker, "Hello logger", new RuntimeException());
155 LOG.error(marker, "Hello logger");
156 LOG.error(marker, "Hello logger {}", 1);
157 LOG.error(marker, "Hello logger {} {} {}", 1, 2, 3);
158 LOG.error(marker, "Hello logger {} {} {}", 1, 2, 3, new RuntimeException());
159 expect.assertObservation();
160 }
161
162 @Test
163 @SuppressFBWarnings("LO_TOSTRING_PARAMETER")
164 public void testIsEnabled() {
165 LOG.debug("Log Config: {}", TestLoggers.sys().toString());
166 Marker marker = MarkerFactory.getMarker("TEST");
167 Assert.assertFalse(LOG.isTraceEnabled());
168 Assert.assertFalse(LOG.isTraceEnabled(marker));
169
170
171 Assert.assertTrue(LOG.isDebugEnabled());
172 Assert.assertTrue(LOG.isDebugEnabled(marker));
173
174 Assert.assertTrue(LOG.isInfoEnabled());
175 Assert.assertTrue(LOG.isInfoEnabled(marker));
176 Assert.assertTrue(LOG.isWarnEnabled());
177 Assert.assertTrue(LOG.isWarnEnabled(marker));
178 Assert.assertTrue(LOG.isErrorEnabled());
179 Assert.assertTrue(LOG.isErrorEnabled(marker));
180 }
181
182 @Test(expected = AssertionError.class)
183 public void testLogging2() {
184 LogAssert expect = TestLoggers.sys().dontExpect("org.spf4j.test", Level.ERROR,
185 LogMatchers.hasFormat("Booo"));
186 LOG.error("Booo", new RuntimeException());
187 expect.assertObservation();
188 }
189
190 @Test
191 @ExpectLog(level = Level.ERROR, categoryClass = TestLoggerFactoryTest.class)
192 @SuppressFBWarnings("UTAO_JUNIT_ASSERTION_ODDITIES_NO_ASSERT")
193 public void testLoggingAnnot() {
194 LOG.error("Booo", new RuntimeException());
195 }
196
197 @Test
198 @ExpectLog(level = Level.ERROR)
199 @SuppressFBWarnings("UTAO_JUNIT_ASSERTION_ODDITIES_NO_ASSERT")
200 @Ignore
201 public void testLoggingAnnot2() {
202 }
203
204 @Test
205 public void testLoggingJul() {
206 LogAssert expect = TestLoggers.sys().expect("my.test", Level.DEBUG,
207 LogMatchers.hasFormat("Bla Bla"),
208 LogMatchers.hasFormat("Boo Boo param"),
209 Matchers.allOf(LogMatchers.hasFormat("test source"),
210 LogMatchers.hasExtraArguments(new Method(TestLoggerFactoryTest.class.getName(),
211 "testLoggingJul"))));
212 java.util.logging.Logger logger = java.util.logging.Logger.getLogger("my.test");
213 logger.info("Bla Bla");
214 logger.log(java.util.logging.Level.FINE, "Boo Boo {0}", "param");
215 logger.logp(java.util.logging.Level.INFO, TestLoggerFactoryTest.class.getName(), "testLoggingJul", "test source");
216 expect.assertObservation();
217 }
218
219 @Test
220 @CollectLogs(minLevel = Level.TRACE)
221 public void testIgnore() {
222 TestLoggers config = TestLoggers.sys();
223 try (HandlerRegistration ir = config.ignore("org.spf4j.test", Level.DEBUG, Level.ERROR)) {
224 LogAssert assrt = config.expect("", Level.TRACE, LogMatchers.hasFormat("trace"));
225 LogAssert assrt2 = config.dontExpect("", Level.DEBUG, LogMatchers.hasFormat("Bla bla"));
226 LOG.debug("Bla bla");
227 LOG.trace("trace");
228 assrt.assertObservation();
229 assrt2.assertObservation();
230 }
231 }
232
233 @Test
234 @CollectLogs(minLevel = Level.OFF)
235 public void testNoIgnore() {
236 Assert.assertFalse(LOG.isDebugEnabled());
237 }
238
239
240 @Test
241 @CollectLogs(minLevel = Level.TRACE)
242 public void testCollect() {
243 TestLoggers config = TestLoggers.sys();
244 try (LogCollection<Long> c = config.collect("org.spf4j.test", Level.INFO, true, Collectors.counting())) {
245 LOG.info("m1");
246 LOG.info("m2");
247 Assert.assertEquals(2L, (long) c.get());
248 }
249 }
250
251 @Test
252 public void testLogJson() {
253 LogAssert expect = TestLoggers.sys().expect("", Level.INFO,
254 Matchers.allOf(LogMatchers.hasFormat("Json Payload"),
255 LogMatchers.hasMatchingExtraArguments(Matchers.arrayContaining(this))));
256 LogPrinter.PRINTER.getAppenderSupplier().register(TestLoggerFactoryTest.class,
257 CoreTextMediaType.APPLICATION_JSON, (o, a) -> {
258 a.append("{\"a\" : \"b\"}");
259 });
260 LOG.info("Json Payload", this);
261 expect.assertObservation();
262 }
263
264 @Test(expected = AssertionError.class)
265 public void testLogging3() {
266 LogAssert expect = TestLoggers.sys().expect("org.spf4j.test", Level.ERROR,
267 LogMatchers.hasFormat("Booo"));
268 expect.assertObservation();
269 }
270
271 @Test
272 public void testLogging33() {
273 LogAssert expect = TestLoggers.sys().dontExpect("org.spf4j.test", Level.ERROR,
274 LogMatchers.hasMatchingFormat(Matchers.equalTo("Booo")));
275 expect.assertObservation();
276 }
277
278 @Ignore
279 @Test
280 @CollectLogs(minLevel = Level.TRACE, collectPrinted = true)
281 public void testLogging4() {
282 LOG.trace("lala");
283 LOG.debug("log {}", 1);
284 LOG.debug("log {} {}", 1, 2);
285 LOG.debug("log {} {} {}", 1, 2, 3);
286 LOG.debug("log {} {} {}", 1, 2, 3, 4);
287 Assert.fail("booo");
288 }
289
290 @Test
291 public void testUncaught() throws InterruptedException {
292 IllegalStateException ex = new IllegalStateException();
293 Thread thread = new Thread(() -> {
294 throw ex;
295 });
296 TestLoggers config = TestLoggers.sys();
297 try (LogAssert obs = config
298 .expectUncaughtException(5, TimeUnit.SECONDS,
299 UncaughtExceptionDetail.hasThrowable(Matchers.equalTo(ex)))) {
300 thread.start();
301 obs.assertObservation();
302 }
303 }
304
305 @SuppressFBWarnings("UTAO_JUNIT_ASSERTION_ODDITIES_NO_ASSERT")
306 @Test
307 public void testUncaught2() throws InterruptedException {
308 TestLoggers config = TestLoggers.sys();
309 LogAssert obs = config
310 .expectUncaughtException(3, TimeUnit.SECONDS,
311 UncaughtExceptionDetail.hasThrowable(Matchers.equalTo(new IllegalStateException())));
312 try {
313 obs.assertObservation();
314 Assert.fail();
315 } catch (AssertionError ex) {
316
317 }
318 }
319
320 @Test
321 public void testLogging5() {
322 LogCollection<ArrayDeque<TestLogRecord>> collect = TestLoggers.sys().collect(Level.DEBUG, 10, true);
323 LOG.debug("log {}", 1);
324 LOG.debug("log {} {}", 1, 2);
325 LOG.debug("log {} {} {}", 1, 2, 3);
326 LOG.debug("log {} {} {}", 1, 2, 3, 4);
327 Assert.assertEquals(4, collect.get().size());
328 }
329
330 @Test
331 public void testExecutionContext() {
332 Assert.assertNotNull(ExecutionContexts.current());
333 }
334
335
336 @Test
337 @Ignore
338 @SuppressFBWarnings({"MDM_THREAD_YIELD", "UTAO_JUNIT_ASSERTION_ODDITIES_NO_ASSERT"})
339 public void testAsyncLogging3() throws InterruptedException {
340 new Thread(() -> {
341 try {
342 LOG.error("async");
343 } catch (Throwable ex) {
344
345 }
346 }).start();
347 Thread.sleep(1000);
348 }
349
350 @Test
351 public void testAsyncLogging() throws InterruptedException {
352 LogAssert expect = TestLoggers.sys().expect("org.spf4j.test.log", Level.ERROR, 3, TimeUnit.SECONDS,
353 LogMatchers.hasFormat("async"));
354 new Thread(() -> {
355 LOG.error("async");
356 }).start();
357 expect.assertObservation();
358 }
359
360 @Test(expected = AssertionError.class)
361 public void testAsyncLogging2() throws InterruptedException {
362 LogAssert expect = TestLoggers.sys().expect("org.spf4j.test.log", Level.ERROR, 3, TimeUnit.SECONDS,
363 LogMatchers.hasFormat("async"));
364 new Thread(() -> {
365 LOG.info("coco");
366 }).start();
367 expect.assertObservation();
368 }
369
370 @Test
371 public void testIntercept() throws InterruptedException {
372 TestLoggers sys = TestLoggers.sys();
373 LogAssert expect = sys.dontExpect("org.spf4j.test.log", Level.INFO, (Matcher) Matchers.anything());
374 HandlerRegistration reg = sys.interceptAllLevels("org.spf4j.test.log", (l) -> null);
375 LOG.info("bla");
376 expect.assertObservation();
377 reg.close();
378 }
379
380 @Test
381 @SuppressFBWarnings("LO_SUSPECT_LOG_CLASS")
382 public void testGreedy() {
383 LogCollection<HashSet<TestLogRecord>> logs
384 = TestLoggers.sys().collect("", Level.INFO, true, Collectors.toCollection(() -> new HashSet<>()));
385 Logger logger = LoggerFactory.getLogger("a.b.c.d");
386 logger.info("test");
387 Set<TestLogRecord> logSet = logs.get();
388 TestLogRecord rec = logSet.iterator().next();
389 Assert.assertTrue(rec.hasAttachment(Attachments.DO_NOT_PRINT));
390 }
391
392 }