1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16 package org.spf4j.test.log;
17
18 import com.google.common.annotations.Beta;
19 import com.google.common.collect.ImmutableList;
20 import com.google.common.collect.ImmutableSortedSet;
21 import com.google.common.collect.Maps;
22 import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
23 import java.util.ArrayDeque;
24 import java.util.Collections;
25 import java.util.List;
26 import java.util.Map;
27 import java.util.SortedSet;
28 import java.util.concurrent.ConcurrentHashMap;
29 import java.util.concurrent.ConcurrentMap;
30 import java.util.concurrent.TimeUnit;
31 import java.util.function.Predicate;
32 import java.util.function.ToIntFunction;
33 import java.util.logging.LogManager;
34 import java.util.stream.Collector;
35 import java.util.stream.Collectors;
36 import javax.annotation.CheckReturnValue;
37 import javax.annotation.Nullable;
38 import javax.annotation.concurrent.GuardedBy;
39 import org.hamcrest.Matcher;
40 import org.hamcrest.MatcherAssert;
41 import org.slf4j.ILoggerFactory;
42 import org.slf4j.Logger;
43 import org.slf4j.LoggerFactory;
44 import org.spf4j.base.Env;
45 import org.spf4j.log.SLF4JBridgeHandler;
46 import org.spf4j.base.ExecutionContext;
47 import org.spf4j.base.ExecutionContexts;
48 import org.spf4j.base.XCollectors;
49 import org.spf4j.log.Level;
50 import org.spf4j.test.log.junit4.Spf4jTestLogRunListenerSingleton;
51
52 import sun.misc.Contended;
53
54
55
56
57
58 @SuppressFBWarnings("SIC_INNER_SHOULD_BE_STATIC_ANON")
59 public final class TestLoggers implements ILoggerFactory {
60
61 public static final boolean EXECUTED_FROM_IDE = TestUtils.isExecutedFromIDE();
62
63 private final ConcurrentMap<String, Logger> loggerMap;
64
65 private final Object sync;
66
67 private final java.util.logging.Logger julGlobal;
68
69 private final java.util.logging.Logger julRoot;
70
71 private final SortedSet<String> expectingErrorsIn;
72
73 private static class Lazy {
74 private static final TestLoggers INSTANCE = new TestLoggers();
75 }
76
77 @GuardedBy("sync")
78 @Contended
79 private volatile LogConfig config;
80
81 public static TestLoggers sys() {
82 return Lazy.INSTANCE;
83 }
84
85 @SuppressWarnings("checkstyle:regexp")
86 private TestLoggers() {
87 sync = new Object();
88 loggerMap = new ConcurrentHashMap<String, Logger>();
89 Level rootPrintLevel = EXECUTED_FROM_IDE
90 ? Level.valueOf(
91 Env.getSystemProperty("spf4j.test.log.rootPrintLevelIDE",
92 new String[] {"spf4j.testLog.rootPrintLevelIDE"}, "DEBUG"))
93 : Level.valueOf(
94 Env.getSystemProperty("spf4j.test.log.rootPrintLevel",
95 new String[] {"spf4j.testLog.rootPrintLevel"}, "INFO"));
96 final Map<String, List<LogHandler>> catHandlers;
97 Map<String, PrintConfig> loadConfig = null;
98 if (EXECUTED_FROM_IDE) {
99 loadConfig = PrintLogConfigsIO.loadConfigFromResource("spf4j-test-prtcfg-ide.properties");
100 }
101 if (loadConfig == null) {
102 loadConfig = PrintLogConfigsIO.loadConfigFromResource("spf4j-test-prtcfg.properties");
103 }
104 if (loadConfig != null) {
105 catHandlers = Maps.newHashMapWithExpectedSize(loadConfig.size());
106 for (PrintConfig pl : loadConfig.values()) {
107 if (pl.getCategory().isEmpty()) {
108 rootPrintLevel = pl.getMinLevel();
109 } else {
110 LogHandler logPrinter;
111 if (pl.isGreedy()) {
112 logPrinter = new GreedyLogPrinter(new LogPrinter(pl.getMinLevel()));
113 } else {
114 logPrinter = new LogPrinter(pl.getMinLevel());
115 }
116 catHandlers.put(pl.getCategory(), Collections.singletonList(logPrinter));
117 }
118 }
119
120 } else {
121 catHandlers = Collections.EMPTY_MAP;
122 }
123 String vals = Env.getSystemProperty("spf4j.test.log.expectingErrorsIn", "spf4j.testLog.expectingErrorsIn");
124 if (vals != null) {
125 expectingErrorsIn = ImmutableSortedSet.orderedBy(LogConfigImpl.REV_STR_COMPARATOR).add(vals.split(",")).build();
126 } else {
127 expectingErrorsIn = ImmutableSortedSet.of();
128 }
129 config = new LogConfigImpl(
130 ImmutableList.of(new LogPrinter(rootPrintLevel),
131 new DefaultAsserter(this::isInExpectingErrorCategories)), catHandlers);
132 LogManager.getLogManager().reset();
133 SLF4JBridgeHandler.removeHandlersForRootLogger();
134 SLF4JBridgeHandler.install();
135 julGlobal = java.util.logging.Logger.getGlobal();
136 julRoot = java.util.logging.Logger.getLogger("");
137 resetJulConfig();
138 }
139
140 public boolean isInExpectingErrorCategories(final String loggername) {
141 if (expectingErrorsIn.isEmpty()) {
142 return false;
143 }
144 for (String cat : expectingErrorsIn.tailSet(loggername)) {
145 if (loggername.startsWith(cat)) {
146 return true;
147 } else if (!loggername.isEmpty() && cat.charAt(0) != loggername.charAt(0)) {
148 break;
149 }
150 }
151 return false;
152 }
153
154 private void resetJulConfig() {
155 java.util.logging.Level julLevel = config.minRootLevel().getJulLevel();
156 julGlobal.setLevel(julLevel);
157 julRoot.setLevel(julLevel);
158 }
159
160 public LogConfig getConfig() {
161 return config;
162 }
163
164
165
166
167
168
169
170 public void print(final String category, final Level level) {
171 interceptInContext(category, new LogPrinter(level));
172 }
173
174 public void print(final String category, final Level level, final boolean greedy) {
175 if (greedy) {
176 interceptInContext(category, new GreedyLogPrinter(new LogPrinter(level)));
177 } else {
178 interceptInContext(category, new LogPrinter(level));
179 }
180 }
181
182
183
184
185
186
187
188 @CheckReturnValue
189 public HandlerRegistration intercept(final String category, final LogHandler handler) {
190 HandlerRegistration reg = () -> {
191 synchronized (sync) {
192 config = config.remove(category, handler);
193 resetJulConfig();
194 }
195 };
196 addConfig(category, handler, ExecutionContexts.current(), reg);
197 return reg;
198 }
199
200 @CheckReturnValue
201 public void interceptInContext(final String category, final LogHandler handler) {
202 ExecutionContext current = ExecutionContexts.current();
203 if (current == null) {
204 throw new IllegalStateException("No execution context available for " + Thread.currentThread());
205 }
206 addConfig(category, handler, current, () -> {
207 synchronized (sync) {
208 config = config.remove(category, handler);
209 resetJulConfig();
210 }
211 });
212 }
213
214
215
216
217
218
219
220
221
222
223
224 @CheckReturnValue
225 public <T> LogCollection<T> collect(final String category, final Level fromLevel,
226 final boolean passThrough,
227 final Collector<TestLogRecord, ?, T> collector) {
228 return collect(category, fromLevel, Level.ERROR, passThrough, collector);
229 }
230
231
232
233
234
235
236 @CheckReturnValue
237 public <T> LogCollection<T> collect(final String category, final Level fromLevel,
238 final boolean passThrough, final Matcher<TestLogRecord> matcher,
239 final Collector<TestLogRecord, ?, T> collector) {
240 return collect(category, fromLevel, passThrough, XCollectors.filtering((log) -> {
241 if (matcher.matches(log)) {
242 log.attach(Attachments.ASSERTED);
243 return true;
244 }
245 return false;
246 }, collector));
247 }
248
249
250
251
252
253
254 @CheckReturnValue
255 public LogAssert expect(final String category, final Level fromLevel,
256 final boolean passThrough, final Matcher<TestLogRecord> matcher,
257 final Matcher<Iterable<TestLogRecord>> matchedMatcher) {
258 LogCollection<List<TestLogRecord>> lc = collect(category, fromLevel, passThrough, XCollectors.filtering((log) -> {
259 if (matcher.matches(log)) {
260 log.attach(Attachments.ASSERTED);
261 return true;
262 }
263 return false;
264 }, Collectors.toList()));
265 return new LogAssert() {
266 @Override
267 public void assertObservation() {
268 MatcherAssert.assertThat(lc.get(), matchedMatcher);
269 }
270
271 @Override
272 public void close() {
273 assertObservation();
274 lc.close();
275 }
276 };
277 }
278
279
280
281
282
283
284
285
286
287
288
289
290 @CheckReturnValue
291 public <T> LogCollection<T> collect(final String category, final Level fromLevel, final Level toLevel,
292 final boolean passThrough,
293 final Collector<TestLogRecord, ?, T> collector) {
294 return collect(category, fromLevel, toLevel, passThrough, collector, (c) -> 0);
295 }
296
297 @CheckReturnValue
298 public <R> LogCollection<R> collect(final String category, final Level fromLevel, final Level toLevel,
299 final boolean passThrough,
300 final Collector<TestLogRecord, ?, R> collector, final ToIntFunction<List<LogHandler>> whereTo) {
301 LogCollectorHandler<?, R> handler =
302 new LogCollectorHandler<>(fromLevel, toLevel, passThrough, collector,
303 (c) -> {
304 config = config.remove(category, c);
305 resetJulConfig();
306 });
307 addConfig(category, handler, ExecutionContexts.current(), handler, whereTo);
308 return handler;
309 }
310
311 private void addConfig(final String category, final LogHandler handler,
312 @Nullable final ExecutionContext ctx, final HandlerRegistration reg) {
313 addConfig(category, handler, ctx, reg, (c) -> 0);
314 }
315
316
317
318
319
320
321
322
323
324
325
326 private void addConfig(final String category, final LogHandler handler,
327 @Nullable final ExecutionContext ctx, final HandlerRegistration reg,
328 final ToIntFunction<List<LogHandler>> whereTo) {
329 validateCorrectLoggingBacked();
330 synchronized (sync) {
331 config = config.add(category, handler, whereTo);
332 resetJulConfig();
333 if (ctx != null) {
334 ctx.addCloseable(reg);
335 }
336 }
337 }
338
339 @SuppressFBWarnings("LO_SUSPECT_LOG_CLASS")
340 private void validateCorrectLoggingBacked() {
341 ValidationUtils.validateLogger(LoggerFactory.getLogger("test"));
342 }
343
344
345
346
347
348
349
350
351 @CheckReturnValue
352 public HandlerRegistration interceptAllLevels(final String category, final AllLevelsLogHandler handler) {
353 return intercept(category, handler);
354 }
355
356
357
358
359
360
361
362
363 @CheckReturnValue
364 public HandlerRegistration ignore(final String category, final Level from, final Level to) {
365 return intercept(category, new ConsumeAllLogs(from, to));
366 }
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381 @CheckReturnValue
382 @SafeVarargs
383 public final LogAssert expect(final String category, final Level minimumLogLevel,
384 final Matcher<TestLogRecord>... matchers) {
385 return logAssert(true, minimumLogLevel, category, matchers);
386 }
387
388 @CheckReturnValue
389 @SafeVarargs
390 public final LogAssert expect(final String category, final Level minimumLogLevel,
391 final long timeout, final TimeUnit unit, final Matcher<TestLogRecord>... matchers) {
392 return logAssert(true, minimumLogLevel, category, timeout, unit, matchers);
393 }
394
395
396
397
398
399
400
401
402 @CheckReturnValue
403 @SafeVarargs
404 public final LogAssert dontExpect(final String category, final Level minimumLogLevel,
405 final Matcher<TestLogRecord>... matchers) {
406 return logAssert(false, minimumLogLevel, category, matchers);
407 }
408
409 @SafeVarargs
410 private final LogAssert logAssert(final boolean assertSeen, final Level minimumLogLevel,
411 final String category, final long timeout, final TimeUnit unit, final Matcher<TestLogRecord>... matchers) {
412 LogMatchingHandler handler = new LogMatchingHandlerAsync(minimumLogLevel, timeout, unit,
413 new ExactLogStreamMatcher(assertSeen, matchers)) {
414
415 private boolean isClosed = false;
416
417 @Override
418 public void close() {
419 synchronized (sync) {
420 if (!isClosed) {
421 config = config.remove(category, this);
422 isClosed = true;
423 resetJulConfig();
424 }
425 }
426 }
427
428 };
429 addConfig(category, handler, ExecutionContexts.current(), handler);
430 return handler;
431 }
432
433
434 @SafeVarargs
435 private final LogAssert logAssert(final boolean assertSeen, final Level minimumLogLevel,
436 final String category, final Matcher<TestLogRecord>... matchers) {
437 LogMatchingHandler handler = new LogMatchingHandler(minimumLogLevel,
438 new ExactLogStreamMatcher(assertSeen, matchers)) {
439
440 private boolean isClosed = false;
441
442 @Override
443 public void close() {
444 synchronized (sync) {
445 if (!isClosed) {
446 config = config.remove(category, this);
447 isClosed = true;
448 resetJulConfig();
449 }
450 }
451 }
452
453 };
454 addConfig(category, handler, ExecutionContexts.current(), handler);
455 return handler;
456 }
457
458
459
460
461
462
463
464
465
466
467 @SafeVarargs
468 public final LogAssert expect(final String category, final Level minimumLogLevel,
469 final int nrTimes, final Matcher<TestLogRecord>... matchers) {
470 Matcher<TestLogRecord>[] newMatchers = new Matcher[matchers.length * nrTimes];
471 for (int i = 0, j = 0; i < nrTimes; i++) {
472 for (Matcher<TestLogRecord> m : matchers) {
473 newMatchers[j++] = m;
474 }
475 }
476 return expect(category, minimumLogLevel, newMatchers);
477 }
478
479 @SafeVarargs
480 public final LogAssert expect(final String category, final Level minimumLogLevel,
481 final int nrTimes, final long timeout, final TimeUnit unit, final Matcher<TestLogRecord>... matchers) {
482 Matcher<TestLogRecord>[] newMatchers = new Matcher[matchers.length * nrTimes];
483 for (int i = 0, j = 0; i < nrTimes; i++) {
484 for (Matcher<TestLogRecord> m : matchers) {
485 newMatchers[j++] = m;
486 }
487 }
488 return expect(category, minimumLogLevel, timeout, unit, newMatchers);
489 }
490
491
492
493
494
495
496
497
498
499 @Beta
500 public LogAssert expectUncaughtException(final long timeout, final TimeUnit unit,
501 final Matcher<UncaughtExceptionDetail> matcher) {
502 ExceptionHandoverRegistry reg = Spf4jTestLogRunListenerSingleton.getListenerInstance()
503 .getUncaughtExceptionHandler();
504 UncaughtExceptionAsserter asserter = new UncaughtExceptionAsserter(timeout, unit, matcher) {
505
506 @Override
507 public void close() {
508 reg.remove(this);
509 }
510 };
511 reg.add(asserter);
512 return asserter;
513 }
514
515
516
517
518
519
520
521
522 public LogCollection<ArrayDeque<TestLogRecord>> collect(final Level minimumLogLevel, final int maxNrLogs,
523 final boolean collectPrinted) {
524 return collect("", minimumLogLevel, maxNrLogs, collectPrinted, null);
525 }
526
527 public LogCollection<ArrayDeque<TestLogRecord>> collect(final Level minimumLogLevel, final int maxNrLogs,
528 final boolean collectPrinted, final String include, final String... excludeCategories) {
529 ArrayDeque adq = new ArrayDeque(maxNrLogs + 1);
530 Collector<TestLogRecord, ArrayDeque<TestLogRecord>, ArrayDeque<TestLogRecord>> truncationCollector
531 = XCollectors.last(() -> adq, maxNrLogs,
532 new TestLogRecordImpl("test", Level.INFO, "Truncated beyond {} ", maxNrLogs));
533 if (excludeCategories.length == 0) {
534 return collect(include, minimumLogLevel, collectPrinted, (Predicate<TestLogRecord>) null, truncationCollector);
535 } else {
536 return collect(include, minimumLogLevel, collectPrinted, (log) -> {
537 String loggerName = log.getLoggerName();
538 for (String cat : excludeCategories) {
539 if (loggerName.startsWith(cat)) {
540 return false;
541 }
542 }
543 return true;
544 }, truncationCollector);
545 }
546 }
547
548
549 public LogCollection<ArrayDeque<TestLogRecord>> collect(final String category, final Level minimumLogLevel,
550 final int maxNrLogs,
551 final boolean collectPrinted, @Nullable final Predicate<TestLogRecord> collectorFilter) {
552 Collector<TestLogRecord, ArrayDeque<TestLogRecord>, ArrayDeque<TestLogRecord>> truncationCollector
553 = XCollectors.last(maxNrLogs,
554 new TestLogRecordImpl("test", Level.INFO, "Truncated beyond {} ", maxNrLogs));
555 return collect(category, minimumLogLevel, collectPrinted, collectorFilter, truncationCollector);
556 }
557
558 public LogCollection<ArrayDeque<TestLogRecord>> collect(
559 final String category, final Level minimumLogLevel,
560 final boolean collectPrinted,
561 final Predicate<TestLogRecord> collectorFilter,
562 final Collector<TestLogRecord, ?, ArrayDeque<TestLogRecord>> pcollector) {
563 Collector<TestLogRecord, ?, ArrayDeque<TestLogRecord>> collector = pcollector;
564 if (collectorFilter != null) {
565 collector = XCollectors.filtering(collectorFilter, collector);
566 }
567 if (!collectPrinted) {
568 return collect(category,
569 minimumLogLevel,
570 Level.ERROR,
571 true,
572 XCollectors.filtering((l) -> !l.hasAttachment(Attachments.PRINTED), collector),
573 List::size);
574 } else {
575 return collect(category, minimumLogLevel, Level.ERROR, true, collector, (c) -> 0);
576 }
577 }
578
579
580
581
582 public Logger getLogger(final String name) {
583 Logger result = loggerMap.get(name);
584 if (result == null) {
585
586 result = new TestLogger(name, TestLoggers.this::getConfig);
587 loggerMap.put(name, result);
588 }
589 return result;
590 }
591
592 @SuppressFBWarnings("EI_EXPOSE_REP")
593 public java.util.logging.Logger getJulGlobal() {
594 return julGlobal;
595 }
596
597 @SuppressFBWarnings("EI_EXPOSE_REP")
598 public java.util.logging.Logger getJulRoot() {
599 return julRoot;
600 }
601
602 @Override
603 public String toString() {
604 return "TestLoggers{ config=" + config + ", loggerMap=" + loggerMap + '}';
605 }
606
607 }